niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #233
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestSetClientTLS66=== PAUSE TestSetClientTLS67=== RUN TestSetClientTLSDoesNotMutateDefaultTransport68=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport69=== RUN TestSetClientTLSErrors70=== PAUSE TestSetClientTLSErrors71=== RUN TestStaticToken72=== PAUSE TestStaticToken73=== RUN TestFileTokenReadsAndCaches74=== PAUSE TestFileTokenReadsAndCaches75=== RUN TestFileTokenMissing76=== PAUSE TestFileTokenMissing77=== RUN TestFileTokenEmpty78=== PAUSE TestFileTokenEmpty79=== RUN TestScriptTokenNoExpiryRerunsEveryCall80=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall81=== RUN TestScriptTokenCachesUntilRefresh82=== PAUSE TestScriptTokenCachesUntilRefresh83=== RUN TestScriptTokenEmptyToken84=== PAUSE TestScriptTokenEmptyToken85=== RUN TestScriptTokenBadJSON86=== PAUSE TestScriptTokenBadJSON87=== RUN TestScriptTokenScriptFails88=== PAUSE TestScriptTokenScriptFails89=== RUN TestScriptTokenEmptyCommand90=== PAUSE TestScriptTokenEmptyCommand91=== CONT TestDoServerRequestAttachesToken92=== CONT TestScriptTokenBadJSON93=== CONT TestScriptTokenEmptyCommand94--- PASS: TestScriptTokenEmptyCommand (0.00s)95=== CONT TestStreamPushReportsEveryPath96=== CONT TestSetClientTLSDoesNotMutateDefaultTransport97=== CONT TestScriptTokenEmptyToken98=== CONT TestScriptTokenCachesUntilRefresh99--- PASS: TestStreamPushReportsEveryPath (0.00s)100=== CONT TestScriptTokenNoExpiryRerunsEveryCall101=== CONT TestFileTokenEmpty102=== CONT TestFileTokenMissing103=== CONT TestFileTokenReadsAndCaches104=== CONT TestStaticToken105=== CONT TestResolveStorePath106=== CONT TestSetClientTLSErrors107=== CONT TestParsePathInfoJSON108=== CONT TestSetClientTLS109=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess110=== CONT TestRateLimiterFeedback111=== CONT TestStreamPushRequestLine112=== CONT TestPathInfoCACompatibility113=== CONT TestStreamPushGivesUpOnDeadServer114=== CONT TestStreamPushIsolatesFailures115=== CONT TestParsePathInfoJSONMultiplePaths116=== CONT TestStreamPushBatchesUnderLoad117=== CONT TestGetStorePathHash118=== CONT TestPathInfoHashCompatibility119=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)120=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)121=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon122=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon123--- PASS: TestStaticToken (0.00s)124=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI125=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI126=== CONT TestShellSplitErrors127--- PASS: TestShellSplitErrors (0.00s)128=== CONT TestConvertHashToNix321292026/09/21 13:47:53 WARN Rate limiter enabled after throttle name=server-test rate=51302026/09/21 13:47:53 ERROR Upload failed error="connection refused" count=201312026/09/21 13:47:53 ERROR Server seems unavailable, giving up on batch untried=171322026/09/21 13:47:53 ERROR Upload failed error="bad path" count=3133--- PASS: TestScriptTokenBadJSON (0.00s)134=== CONT TestShellSplit135--- PASS: TestShellSplit (0.00s)136--- PASS: TestFileTokenMissing (0.00s)137=== CONT TestPartSizeForNAR138--- PASS: TestFileTokenReadsAndCaches (0.00s)139=== RUN TestGetStorePathHash/valid_store_path140=== CONT TestScriptTokenScriptFails141=== RUN TestRateLimiterFeedback/429_enables_limiter142=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512143=== RUN TestConvertHashToNix32/SRI_format_to_Nix32144=== PAUSE TestGetStorePathHash/valid_store_path145=== PAUSE TestRateLimiterFeedback/429_enables_limiter146=== CONT TestDumpPathSingleFile147=== RUN TestPartSizeForNAR/zero_stays_at_minimum148=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1492026/09/21 13:47:53 ERROR Upload failed error=boom count=1150=== RUN TestPathInfoCACompatibility/null_ca_field151--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)152--- PASS: TestStreamPushIsolatesFailures (0.00s)153--- PASS: TestResolveStorePath (0.00s)154=== CONT TestDumpPathMatchesNix155=== PAUSE TestPathInfoCACompatibility/null_ca_field156=== CONT TestDumpPathWriterError157=== RUN TestPathInfoCACompatibility/old_string_format_-_text158--- PASS: TestFileTokenEmpty (0.00s)159=== RUN TestParsePathInfoJSON/Nix_format160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512162=== CONT TestDoWithRetry_BodyReplayedViaGetBody163=== CONT TestCaseHackSuffix164=== CONT TestFilterOversizedClosures165=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32166=== CONT TestEncodeNixBase32WithRealHash167=== CONT TestEncodeNixBase32168=== RUN TestEncodeNixBase32/test_string_hash169=== PAUSE TestEncodeNixBase32/test_string_hash170=== RUN TestRateLimiterFeedback/503_enables_limiter171=== CONT TestUploadMultipart_SupersededByPeer172=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text174=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths175--- PASS: TestScriptTokenEmptyToken (0.01s)176=== RUN TestSetClientTLSErrors/missing_cert_file177=== PAUSE TestParsePathInfoJSON/Nix_format178=== RUN TestFilterOversizedClosures/no_limit_keeps_everything179=== CONT TestUploadMultipart_PartsInParallel180=== CONT TestRegisterUploadedObjectReusesConnections181=== RUN TestConvertHashToNix32/already_Nix32_format182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1832026/09/21 13:47:53 WARN Rate limiter enabled after throttle name=server-test rate=51842026/09/21 13:47:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42681185=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)186=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive187--- PASS: TestDoServerRequestAttachesToken (0.01s)188=== RUN TestPartSizeForNAR/small_stays_at_minimum189=== PAUSE TestSetClientTLSErrors/missing_cert_file190=== RUN TestParsePathInfoJSON/Lix_format191=== PAUSE TestParsePathInfoJSON/Lix_format192--- PASS: TestScriptTokenScriptFails (0.00s)193--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)194--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)195--- PASS: TestEncodeNixBase32WithRealHash (0.00s)196=== RUN TestParsePathInfoJSON/empty_input197=== RUN TestSetClientTLSErrors/missing_key_file198=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon199=== PAUSE TestSetClientTLSErrors/missing_key_file200=== RUN TestSetClientTLSErrors/missing_ca_file201=== PAUSE TestSetClientTLSErrors/missing_ca_file202=== RUN TestSetClientTLSErrors/invalid_ca_file203=== PAUSE TestSetClientTLSErrors/invalid_ca_file204=== CONT TestSetClientTLSErrors/missing_cert_file205=== PAUSE TestRateLimiterFeedback/503_enables_limiter206=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter207=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter208=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter209=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter210=== CONT TestRateLimiterFeedback/429_enables_limiter2112026/09/21 13:47:53 WARN Rate limiter backed off name=server-test rate=52122026/09/21 13:47:53 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42681213=== RUN TestSetClientTLS/rejects_connection_without_client_cert214=== CONT TestSetClientTLSErrors/invalid_ca_file215=== PAUSE TestPartSizeForNAR/small_stays_at_minimum216=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum217=== PAUSE TestParsePathInfoJSON/empty_input218=== RUN TestParsePathInfoJSON/whitespace_only219=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert220=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA221=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA222=== RUN TestSetClientTLS/preserves_debug_logging_transport2232026/09/21 13:47:53 WARN Rate limiter enabled after throttle name=server-test rate=5224=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2252026/09/21 13:47:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40553226=== RUN TestEncodeNixBase32/empty_input227=== PAUSE TestConvertHashToNix32/already_Nix32_format228=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error229=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive230=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths231=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI232=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512233--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)234=== RUN TestUploadMultipart_SupersededByPeer/exists235=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter236=== RUN TestPathInfoCACompatibility/new_structured_format_-_text237=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text238=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2392026/09/21 13:47:53 WARN Rate limiter backed off name=server-test rate=5240=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method241=== CONT TestSetClientTLS/preserves_debug_logging_transport242=== CONT TestSetClientTLSErrors/missing_ca_file243=== CONT TestPathInfoCACompatibility/null_ca_field244=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method245=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths246=== CONT TestSetClientTLS/rejects_connection_without_client_cert247=== CONT TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestSetClientTLSErrors/missing_key_file249=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive250=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths251=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter252=== CONT TestPathInfoCACompatibility/old_string_format_-_text253=== RUN TestConvertHashToNix32/invalid_format254=== PAUSE TestConvertHashToNix32/invalid_format255=== CONT TestConvertHashToNix32/SRI_format_to_Nix32256=== PAUSE TestParsePathInfoJSON/whitespace_only257=== CONT TestConvertHashToNix32/invalid_format258=== PAUSE TestEncodeNixBase32/empty_input259=== CONT TestEncodeNixBase32/test_string_hash260=== CONT TestConvertHashToNix32/already_Nix32_format261=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error262=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error263=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error264=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error265=== CONT TestGetStorePathHash/valid_store_path266=== CONT TestEncodeNixBase32/empty_input267--- PASS: TestDumpPathSingleFile (0.04s)268=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error269=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error270=== CONT TestGetStorePathHash/basename_without_hyphen_should_error271=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum272--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)273=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts274=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts275=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA276=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything277=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped278=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped279=== RUN TestFilterOversizedClosures/all_closures_skipped280=== PAUSE TestFilterOversizedClosures/all_closures_skipped281=== CONT TestFilterOversizedClosures/no_limit_keeps_everything282=== RUN TestParsePathInfoJSON/invalid_JSON283=== PAUSE TestParsePathInfoJSON/invalid_JSON284=== CONT TestParsePathInfoJSON/Nix_format285=== CONT TestFilterOversizedClosures/all_closures_skipped286=== CONT TestParsePathInfoJSON/empty_input2872026/09/21 13:47:53 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=50288=== PAUSE TestUploadMultipart_SupersededByPeer/exists289=== CONT TestParsePathInfoJSON/invalid_JSON290=== RUN TestUploadMultipart_SupersededByPeer/missing291=== CONT TestRateLimiterFeedback/503_enables_limiter292=== RUN TestPartSizeForNAR/1_TiB293--- PASS: TestPathInfoHashCompatibility (0.01s)294 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)295 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)296 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)297 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)298=== CONT TestParsePathInfoJSON/Lix_format299=== PAUSE TestPartSizeForNAR/1_TiB300=== RUN TestPartSizeForNAR/5_TiB_S3_max_object301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== RUN TestPartSizeForNAR/capped_at_5_GiB303=== PAUSE TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestPartSizeForNAR/zero_stays_at_minimum305=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3062026/09/21 13:47:53 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=2000307=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts308=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum309=== CONT TestPartSizeForNAR/small_stays_at_minimum310=== PAUSE TestUploadMultipart_SupersededByPeer/missing311=== CONT TestUploadMultipart_SupersededByPeer/exists312=== CONT TestPartSizeForNAR/1_TiB313=== CONT TestPartSizeForNAR/capped_at_5_GiB314=== CONT TestPartSizeForNAR/5_TiB_S3_max_object315=== CONT TestParsePathInfoJSON/whitespace_only316--- PASS: TestParsePathInfoJSONMultiplePaths (0.05s)317 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)318 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)319=== CONT TestUploadMultipart_SupersededByPeer/missing3202026/09/21 13:47:53 WARN Rate limiter enabled after throttle name=server-test rate=53212026/09/21 13:47:53 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:34453322--- PASS: TestPathInfoCACompatibility (0.05s)323 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)324 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)325 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)326 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)327 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)328--- PASS: TestFilterOversizedClosures (0.04s)329 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)330 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)331 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3322026/09/21 13:47:53 WARN Rate limiter backed off name=server-test rate=5333--- PASS: TestPartSizeForNAR (0.05s)334 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)335 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)336 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)337 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)338 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)339 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)340 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)341--- PASS: TestSetClientTLSErrors (0.05s)342 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)343 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)345 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)346--- PASS: TestConvertHashToNix32 (0.05s)347 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)348 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)349 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)350--- PASS: TestGetStorePathHash (0.05s)351 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)352 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)353 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)354 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)355--- PASS: TestEncodeNixBase32 (0.04s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358--- PASS: TestParsePathInfoJSON (0.05s)359 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)361 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)362 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)363 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)364--- PASS: TestRateLimiterFeedback (0.05s)365 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)366 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)369--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)370 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)371 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3722026/09/21 13:47:53 http: TLS handshake error from 127.0.0.1:35682: remote error: tls: bad certificate373--- PASS: TestSetClientTLS (0.05s)374 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)375 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)376 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)377--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)378--- PASS: TestStreamPushRequestLine (0.08s)379--- PASS: TestCaseHackSuffix (0.07s)380--- PASS: TestDumpPathWriterError (0.08s)381--- PASS: TestStreamPushBatchesUnderLoad (0.10s)382--- PASS: TestDumpPathMatchesNix (0.13s)383--- PASS: TestUploadMultipart_PartsInParallel (0.66s)384--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)385PASS386Running server tests...387The files belonging to this database system will be owned by user "nixbld".388This user must also own the server process.389390The database cluster will be initialized with locale "C".391The default database encoding has accordingly been set to "SQL_ASCII".392The default text search configuration will be set to "english".393394Data page checksums are enabled.395396creating directory /build/postgres2073832623/data ... ok397creating subdirectories ... ok398selecting dynamic shared memory implementation ... posix399selecting default "max_connections" ... 100400selecting default "shared_buffers" ... 128MB401selecting default time zone ... UTC402creating configuration files ... ok403running bootstrap script ... ok404performing post-bootstrap initialization ... ok405syncing data to disk ... ok406407initdb: warning: enabling "trust" authentication for local connections408initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.409410Success. You can now start the database server using:411412 pg_ctl -D /build/postgres2073832623/data -l logfile start413414/build/postgres2073832623:5432 - no response4152026-09-21 13:47:55.014 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4162026-09-21 13:47:55.014 UTC [128] LOG: listening on Unix socket "/build/postgres2073832623/.s.PGSQL.5432"4172026-09-21 13:47:55.019 UTC [135] LOG: database system was shut down at 2026-09-21 13:47:54 UTC4182026-09-21 13:47:55.022 UTC [128] LOG: database system is ready to accept connections419/build/postgres2073832623:5432 - accepting connections420=== RUN TestService_AuthMiddleware421=== PAUSE TestService_AuthMiddleware422=== RUN TestService_AuthMiddleware_MTLSProxyHeader423=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader424=== RUN TestService_AuthMiddleware_MTLSBoundSubjects425=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects426=== RUN TestService_ReadAuthMiddleware427=== PAUSE TestService_ReadAuthMiddleware428=== RUN TestService_AuthMiddleware_OIDC429=== PAUSE TestService_AuthMiddleware_OIDC430=== RUN TestService_RequireScope_OIDC431=== PAUSE TestService_RequireScope_OIDC432=== RUN TestService_ReadScope_PublicByDefault433=== PAUSE TestService_ReadScope_PublicByDefault434=== RUN TestCacheConfigHandler435=== PAUSE TestCacheConfigHandler436=== RUN TestCacheStatsHandler437=== PAUSE TestCacheStatsHandler438=== RUN TestClientCADerivations439=== PAUSE TestClientCADerivations440=== RUN TestClientErrorHandling441=== PAUSE TestClientErrorHandling442=== RUN TestClientIntegration443=== PAUSE TestClientIntegration444=== RUN TestClientMultipleUploads445=== PAUSE TestClientMultipleUploads446=== RUN TestClientWithDependencies447=== PAUSE TestClientWithDependencies448=== RUN TestClientSharedPathCommittedMidPush449=== PAUSE TestClientSharedPathCommittedMidPush450=== RUN TestPinProtectsFromGC451=== PAUSE TestPinProtectsFromGC452=== RUN TestResolveDBConnectionString453=== PAUSE TestResolveDBConnectionString454=== RUN TestLeadElectsOneAndHandsOver455=== PAUSE TestLeadElectsOneAndHandsOver456=== RUN TestLeadIncumbentWinsAfterRestart4572026-09-21 13:47:56.359 UTC [368] ERROR: relation "goose_db_version" does not exist at character 364582026-09-21 13:47:56.359 UTC [368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4592026/09/21 13:47:56 OK 20241026095416_initial_model.sql (11.19ms)4602026/09/21 13:47:56 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)4612026/09/21 13:47:56 OK 20251218171726_add_pins.sql (2.69ms)4622026/09/21 13:47:56 OK 20260628120000_add_object_size_and_stats.sql (2.48ms)4632026/09/21 13:47:56 OK 20260905000000_add_claims.sql (3.07ms)4642026/09/21 13:47:56 OK 20260920000000_drop_claims.sql (1.57ms)4652026/09/21 13:47:56 goose: successfully migrated database to version: 202609200000004662026/09/21 13:47:56 OK 1_commit_pending_closure.sql (1.71ms)4672026/09/21 13:47:56 OK 2_object_stats_trigger.sql (704.27µs)4682026/09/21 13:47:56 goose: up to current file version: 24692026/09/21 13:47:57 INFO lead: acquired remote=192.0.2.1:12344702026/09/21 13:47:57 INFO lead: released remote=192.0.2.1:12344712026/09/21 13:47:58 INFO lead: acquired remote=192.0.2.1:12344722026/09/21 13:47:58 INFO lead: released remote=192.0.2.1:1234473--- PASS: TestLeadIncumbentWinsAfterRestart (1.75s)474=== RUN TestLeadEndsOnShutdown475=== PAUSE TestLeadEndsOnShutdown476=== RUN TestGCAdvisoryLockBlocksConcurrentRun4772026-09-21 13:47:58.075 UTC [382] ERROR: relation "goose_db_version" does not exist at character 364782026-09-21 13:47:58.075 UTC [382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4792026/09/21 13:47:58 OK 20241026095416_initial_model.sql (10.21ms)4802026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)4812026/09/21 13:47:58 OK 20251218171726_add_pins.sql (3.21ms)4822026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (2.49ms)4832026/09/21 13:47:58 OK 20260905000000_add_claims.sql (2.39ms)4842026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (1.57ms)4852026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000004862026/09/21 13:47:58 OK 1_commit_pending_closure.sql (1.87ms)4872026/09/21 13:47:58 OK 2_object_stats_trigger.sql (735.39µs)4882026/09/21 13:47:58 goose: up to current file version: 2489--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.18s)490=== RUN TestGCBugBareHashReferences491=== PAUSE TestGCBugBareHashReferences492=== RUN TestGCMetrics493=== PAUSE TestGCMetrics494=== RUN TestGCTaskStore_StartNew495=== PAUSE TestGCTaskStore_StartNew496=== RUN TestGCTaskStore_DeduplicateSameParams497=== PAUSE TestGCTaskStore_DeduplicateSameParams498=== RUN TestGCTaskStore_ConflictDifferentParams499=== PAUSE TestGCTaskStore_ConflictDifferentParams500=== RUN TestGCTaskStore_GetEmpty501=== PAUSE TestGCTaskStore_GetEmpty502=== RUN TestGCTaskStore_GetReturnsLatest503=== PAUSE TestGCTaskStore_GetReturnsLatest504=== RUN TestGCTaskStore_CompletedAllowsNewTask505=== PAUSE TestGCTaskStore_CompletedAllowsNewTask506=== RUN TestGCTaskStore_PhaseUpdates507=== PAUSE TestGCTaskStore_PhaseUpdates508=== RUN TestGCTaskStore_Fail509=== PAUSE TestGCTaskStore_Fail510=== RUN TestGracefulShutdownDrainsInflight511=== PAUSE TestGracefulShutdownDrainsInflight512=== RUN TestService_healthCheckHandler513=== PAUSE TestService_healthCheckHandler514=== RUN TestService_readinessHandler515=== PAUSE TestService_readinessHandler516=== RUN TestGenerateLandingPage517=== PAUSE TestGenerateLandingPage518=== RUN TestCacheConfigHandlerMaxNarSize519=== PAUSE TestCacheConfigHandlerMaxNarSize520=== RUN TestCreatePendingClosureRejectsOversizedNAR521=== PAUSE TestCreatePendingClosureRejectsOversizedNAR522=== RUN TestNARDeduplicationMetadataUploadBug523=== PAUSE TestNARDeduplicationMetadataUploadBug524=== RUN TestMetricsInventory525=== PAUSE TestMetricsInventory526=== RUN TestService_NativeMTLS527=== PAUSE TestService_NativeMTLS528=== RUN TestServerTLSConfig529=== PAUSE TestServerTLSConfig530=== RUN TestMultipartCleanup531=== PAUSE TestMultipartCleanup532=== RUN TestObjectStatsTrigger533=== PAUSE TestObjectStatsTrigger534=== RUN TestOrphanedObjectsGC535=== PAUSE TestOrphanedObjectsGC536=== RUN TestOrphanedObjectsGCStressTest537=== PAUSE TestOrphanedObjectsGCStressTest538=== RUN TestResurrectedObjectNotDeleted539=== PAUSE TestResurrectedObjectNotDeleted540=== RUN TestParseSingleRange541=== PAUSE TestParseSingleRange542=== RUN TestIsValidCachePath543=== PAUSE TestIsValidCachePath544=== RUN TestReadProxyNarinfo545=== PAUSE TestReadProxyNarinfo546=== RUN TestReadProxyNarinfoAlreadyDecompressed547=== PAUSE TestReadProxyNarinfoAlreadyDecompressed548=== RUN TestReadProxyNarStreaming549=== PAUSE TestReadProxyNarStreaming550=== RUN TestReadProxy404551=== PAUSE TestReadProxy404552=== RUN TestReadProxyInvalidPath553=== PAUSE TestReadProxyInvalidPath554=== RUN TestReadProxyHead555=== PAUSE TestReadProxyHead556=== RUN TestReadProxyConditionalGet557=== PAUSE TestReadProxyConditionalGet558=== RUN TestReadProxyRootRedirectsToIndexHTML559=== PAUSE TestReadProxyRootRedirectsToIndexHTML560=== RUN TestReadProxyDisabled561=== PAUSE TestReadProxyDisabled562=== RUN TestReadRedirectNar563=== PAUSE TestReadRedirectNar564=== RUN TestReadRedirectKeepsNarinfoProxied565=== PAUSE TestReadRedirectKeepsNarinfoProxied566=== RUN TestReadProxyRangeRequest567=== PAUSE TestReadProxyRangeRequest568=== RUN TestReadRedirectUsesPublicS3URL569=== PAUSE TestReadRedirectUsesPublicS3URL570=== RUN TestRedundantMultipartUpload571=== PAUSE TestRedundantMultipartUpload572=== RUN TestCompleteMultipartUpload_ErrorButObjectExists573=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists574=== RUN TestCompletedNarNotReofferedAcrossClosures575=== PAUSE TestCompletedNarNotReofferedAcrossClosures576=== RUN TestPresignedUploadRegisteredBeforeCommit577=== PAUSE TestPresignedUploadRegisteredBeforeCommit578=== RUN TestService_Rustfstest579=== PAUSE TestService_Rustfstest580=== RUN TestParseSize581=== PAUSE TestParseSize582=== RUN TestSkippedUploadsHandler583=== PAUSE TestSkippedUploadsHandler584=== RUN TestSystemdListenerNotActivated585--- PASS: TestSystemdListenerNotActivated (0.00s)586=== RUN TestWatchdogBeatsWhenHealthy587--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)588=== RUN TestWatchdogSkipsWhenUnhealthy5892026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5902026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/21 13:47:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"599--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)600=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle601=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle602=== RUN TestProxyWriteTimeout603=== PAUSE TestProxyWriteTimeout604=== RUN TestIsValidUploadKey605=== PAUSE TestIsValidUploadKey606=== RUN TestUploadHandlersRejectInvalidKeys607=== PAUSE TestUploadHandlersRejectInvalidKeys608=== RUN TestUploadHandlersRejectOversizedBody609=== PAUSE TestUploadHandlersRejectOversizedBody610=== RUN TestService_cleanupPendingClosuresHandler611=== PAUSE TestService_cleanupPendingClosuresHandler612=== RUN TestService_createPendingClosureHandler613=== PAUSE TestService_createPendingClosureHandler614=== RUN TestService_verifyS3Integrity615=== PAUSE TestService_verifyS3Integrity616=== RUN TestCompleteMultipartUnregistered617=== PAUSE TestCompleteMultipartUnregistered618=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT619=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT620=== CONT TestService_AuthMiddleware621=== CONT TestServerTLSConfig622=== CONT TestCompletedNarNotReofferedAcrossClosures623=== CONT TestReadProxyNarStreaming624=== CONT TestReadRedirectUsesPublicS3URL625=== CONT TestReadProxyRootRedirectsToIndexHTML626=== CONT TestRedundantMultipartUpload627=== CONT TestReadRedirectNar628=== CONT TestGCBugBareHashReferences629=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT630=== CONT TestCompleteMultipartUnregistered631=== CONT TestService_verifyS3Integrity632=== CONT TestService_createPendingClosureHandler633=== CONT TestService_cleanupPendingClosuresHandler634=== CONT TestUploadHandlersRejectOversizedBody635=== CONT TestUploadHandlersRejectInvalidKeys636=== CONT TestIsValidUploadKey637=== RUN TestIsValidUploadKey/narinfo638=== PAUSE TestIsValidUploadKey/narinfo639=== RUN TestIsValidUploadKey/nar_zst640=== CONT TestProxyWriteTimeout641=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle642=== CONT TestSkippedUploadsHandler643=== CONT TestParseSize644=== CONT TestService_Rustfstest645=== CONT TestPresignedUploadRegisteredBeforeCommit646=== RUN TestServerTLSConfig/no_client_CA647=== CONT TestReadProxyRangeRequest648=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info649=== RUN TestProxyWriteTimeout/narinfo650--- PASS: TestParseSize (0.00s)651=== CONT TestReadProxyDisabled652=== PAUSE TestIsValidUploadKey/nar_zst653=== RUN TestIsValidUploadKey/nar_xz654=== PAUSE TestIsValidUploadKey/nar_xz655=== RUN TestIsValidUploadKey/nar_plain656=== PAUSE TestIsValidUploadKey/nar_plain657=== RUN TestIsValidUploadKey/listing658=== PAUSE TestIsValidUploadKey/listing659=== PAUSE TestServerTLSConfig/no_client_CA660=== PAUSE TestProxyWriteTimeout/narinfo661=== RUN TestServerTLSConfig/missing_CA_file662=== PAUSE TestServerTLSConfig/missing_CA_file663=== RUN TestProxyWriteTimeout/1_GiB_nar664=== RUN TestIsValidUploadKey/build_log665=== RUN TestServerTLSConfig/not_a_PEM_file6662026/09/21 13:47:58 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000667=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info668=== PAUSE TestServerTLSConfig/not_a_PEM_file669=== PAUSE TestProxyWriteTimeout/1_GiB_nar670=== PAUSE TestIsValidUploadKey/build_log671=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal672=== RUN TestProxyWriteTimeout/10_GiB_nar673=== RUN TestIsValidUploadKey/build_log_home-manager_file674=== PAUSE TestIsValidUploadKey/build_log_home-manager_file675=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal676=== CONT TestResurrectedObjectNotDeleted677=== RUN TestIsValidUploadKey/build_log_plus_in_name678=== PAUSE TestProxyWriteTimeout/10_GiB_nar679=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key680=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key681=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key682=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key683=== PAUSE TestIsValidUploadKey/build_log_plus_in_name684=== RUN TestProxyWriteTimeout/unknown_size685=== PAUSE TestProxyWriteTimeout/unknown_size686=== CONT TestReadProxyNarinfoAlreadyDecompressed687=== CONT TestReadProxyNarinfo688=== RUN TestIsValidUploadKey/build_log_question_mark689=== PAUSE TestIsValidUploadKey/build_log_question_mark690=== RUN TestIsValidUploadKey/build_log_equals691=== PAUSE TestIsValidUploadKey/build_log_equals692=== RUN TestIsValidUploadKey/realisation693=== PAUSE TestIsValidUploadKey/realisation694=== RUN TestIsValidUploadKey/realisation_plus_in_output695=== PAUSE TestIsValidUploadKey/realisation_plus_in_output696=== RUN TestIsValidUploadKey/nix-cache-info697=== PAUSE TestIsValidUploadKey/nix-cache-info698=== RUN TestIsValidUploadKey/index.html699=== PAUSE TestIsValidUploadKey/index.html700=== RUN TestIsValidUploadKey/narinfo_key,_nar_type701=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type702=== RUN TestIsValidUploadKey/nar_key,_narinfo_type703=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type704=== RUN TestIsValidUploadKey/listing_key,_narinfo_type705=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type706=== RUN TestIsValidUploadKey/traversal707=== PAUSE TestIsValidUploadKey/traversal708=== RUN TestIsValidUploadKey/traversal_nar709=== PAUSE TestIsValidUploadKey/traversal_nar710=== RUN TestIsValidUploadKey/absolute711=== PAUSE TestIsValidUploadKey/absolute712=== RUN TestIsValidUploadKey/empty_key713=== PAUSE TestIsValidUploadKey/empty_key714=== RUN TestIsValidUploadKey/unknown_type715=== PAUSE TestIsValidUploadKey/unknown_type716=== CONT TestIsValidCachePath717=== RUN TestIsValidCachePath/narinfo718=== PAUSE TestIsValidCachePath/narinfo719=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars720=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars721=== RUN TestIsValidCachePath/nar_zst722=== PAUSE TestIsValidCachePath/nar_zst723=== RUN TestIsValidCachePath/nar_xz724=== PAUSE TestIsValidCachePath/nar_xz725=== RUN TestIsValidCachePath/nar_bz2726=== PAUSE TestIsValidCachePath/nar_bz2727=== RUN TestIsValidCachePath/nar_uncompressed728=== PAUSE TestIsValidCachePath/nar_uncompressed729=== RUN TestIsValidCachePath/ls730=== PAUSE TestIsValidCachePath/ls731=== RUN TestIsValidCachePath/log732=== PAUSE TestIsValidCachePath/log733=== RUN TestIsValidCachePath/realisation734=== PAUSE TestIsValidCachePath/realisation735=== RUN TestIsValidCachePath/nix-cache-info736=== PAUSE TestIsValidCachePath/nix-cache-info737=== RUN TestIsValidCachePath/index.html738=== PAUSE TestIsValidCachePath/index.html739=== RUN TestIsValidCachePath/traversal_parent740=== PAUSE TestIsValidCachePath/traversal_parent741=== RUN TestIsValidCachePath/traversal_in_middle742=== PAUSE TestIsValidCachePath/traversal_in_middle743=== RUN TestIsValidCachePath/invalid_char_e744=== PAUSE TestIsValidCachePath/invalid_char_e745=== RUN TestIsValidCachePath/invalid_char_u746=== PAUSE TestIsValidCachePath/invalid_char_u747=== RUN TestIsValidCachePath/random_path748=== PAUSE TestIsValidCachePath/random_path749=== RUN TestIsValidCachePath/empty750=== PAUSE TestIsValidCachePath/empty751=== RUN TestIsValidCachePath/leading_slash752=== PAUSE TestIsValidCachePath/leading_slash753=== RUN TestIsValidCachePath/wrong_extension754=== PAUSE TestIsValidCachePath/wrong_extension755=== RUN TestIsValidCachePath/short_hash756=== PAUSE TestIsValidCachePath/short_hash757=== CONT TestParseSingleRange758=== RUN TestParseSingleRange/none759=== PAUSE TestParseSingleRange/none760=== RUN TestParseSingleRange/unknown_unit761=== PAUSE TestParseSingleRange/unknown_unit762=== RUN TestParseSingleRange/multi-range_ignored763=== PAUSE TestParseSingleRange/multi-range_ignored764=== RUN TestParseSingleRange/malformed_no_dash765=== PAUSE TestParseSingleRange/malformed_no_dash766=== RUN TestParseSingleRange/malformed_both_empty767=== PAUSE TestParseSingleRange/malformed_both_empty768=== RUN TestParseSingleRange/malformed_end_before_start769=== PAUSE TestParseSingleRange/malformed_end_before_start770--- PASS: TestSkippedUploadsHandler (0.07s)771=== CONT TestClientErrorHandling772=== RUN TestClientErrorHandling/InvalidStorePath773=== PAUSE TestClientErrorHandling/InvalidStorePath774=== RUN TestParseSingleRange/closed775=== PAUSE TestParseSingleRange/closed776=== RUN TestClientErrorHandling/InvalidAuthToken777=== RUN TestParseSingleRange/open-ended778=== PAUSE TestParseSingleRange/open-ended779=== PAUSE TestClientErrorHandling/InvalidAuthToken780=== RUN TestParseSingleRange/end_clamped_to_size781=== RUN TestClientErrorHandling/ServerNotAvailable782=== PAUSE TestParseSingleRange/end_clamped_to_size783=== RUN TestParseSingleRange/suffix784=== PAUSE TestClientErrorHandling/ServerNotAvailable785=== PAUSE TestParseSingleRange/suffix786=== CONT TestLeadEndsOnShutdown787=== RUN TestParseSingleRange/suffix_exceeds_size788=== PAUSE TestParseSingleRange/suffix_exceeds_size789=== RUN TestParseSingleRange/single_byte790=== PAUSE TestParseSingleRange/single_byte791=== RUN TestParseSingleRange/start_past_EOF792=== PAUSE TestParseSingleRange/start_past_EOF793=== RUN TestParseSingleRange/start_far_past_EOF794=== PAUSE TestParseSingleRange/start_far_past_EOF795=== CONT TestLeadElectsOneAndHandsOver7962026-09-21 13:47:58.515 UTC [446] ERROR: relation "goose_db_version" does not exist at character 367972026-09-21 13:47:58.515 UTC [446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026-09-21 13:47:58.517 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367992026-09-21 13:47:58.517 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8002026-09-21 13:47:58.541 UTC [450] ERROR: relation "goose_db_version" does not exist at character 368012026-09-21 13:47:58.541 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026-09-21 13:47:58.555 UTC [451] ERROR: relation "goose_db_version" does not exist at character 368032026-09-21 13:47:58.555 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026-09-21 13:47:58.559 UTC [452] ERROR: relation "goose_db_version" does not exist at character 368052026-09-21 13:47:58.559 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC806=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts807=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts808=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure809=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure810=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart811=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart812=== CONT TestResolveDBConnectionString8132026/09/21 13:47:58 OK 20241026095416_initial_model.sql (82.71ms)814=== RUN TestResolveDBConnectionString/flag_wins815=== PAUSE TestResolveDBConnectionString/flag_wins816=== RUN TestResolveDBConnectionString/file_when_flag_empty817=== PAUSE TestResolveDBConnectionString/file_when_flag_empty818=== RUN TestResolveDBConnectionString/missing_file_is_an_error819=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error820=== RUN TestResolveDBConnectionString/PGHOST_allows_empty821=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty822=== RUN TestResolveDBConnectionString/nothing_configured823=== PAUSE TestResolveDBConnectionString/nothing_configured824=== CONT TestPinProtectsFromGC8252026-09-21 13:47:58.625 UTC [455] ERROR: relation "goose_db_version" does not exist at character 368262026-09-21 13:47:58.625 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8272026-09-21 13:47:58.626 UTC [456] ERROR: relation "goose_db_version" does not exist at character 368282026-09-21 13:47:58.626 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026/09/21 13:47:58 OK 20241026095416_initial_model.sql (91.38ms)8302026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (10.05ms)8312026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (3.29ms)8322026/09/21 13:47:58 OK 20251218171726_add_pins.sql (10.44ms)8332026/09/21 13:47:58 OK 20251218171726_add_pins.sql (8.02ms)8342026/09/21 13:47:58 OK 20241026095416_initial_model.sql (25.04ms)8352026/09/21 13:47:58 OK 20241026095416_initial_model.sql (42.28ms)8362026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (16.41ms)8372026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (19.29ms)8382026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (3.93ms)8392026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.15ms)8402026/09/21 13:47:58 OK 20241026095416_initial_model.sql (27.3ms)8412026/09/21 13:47:58 OK 20260905000000_add_claims.sql (7.1ms)8422026/09/21 13:47:58 OK 20241026095416_initial_model.sql (29.03ms)8432026/09/21 13:47:58 OK 20241026095416_initial_model.sql (39.19ms)8442026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.82ms)8452026/09/21 13:47:58 OK 20251218171726_add_pins.sql (10.46ms)8462026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.11ms)8472026/09/21 13:47:58 OK 20260905000000_add_claims.sql (12.33ms)8482026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (7.69ms)8492026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000008502026/09/21 13:47:58 OK 20251218171726_add_pins.sql (11.85ms)8512026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (6.14ms)8522026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.4ms)8532026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.91ms)8542026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.55ms)8552026/09/21 13:47:58 OK 1_commit_pending_closure.sql (5.39ms)8562026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (7.03ms)8572026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000008582026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.64ms)8592026/09/21 13:47:58 OK 2_object_stats_trigger.sql (3.07ms)8602026/09/21 13:47:58 goose: up to current file version: 28612026/09/21 13:47:58 OK 20260905000000_add_claims.sql (14.95ms)8622026/09/21 13:47:58 OK 20251218171726_add_pins.sql (18.69ms)8632026/09/21 13:47:58 OK 1_commit_pending_closure.sql (13.23ms)8642026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (16.52ms)8652026/09/21 13:47:58 OK 20260905000000_add_claims.sql (14.36ms)8662026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (17.31ms)8672026/09/21 13:47:58 OK 2_object_stats_trigger.sql (3.49ms)8682026/09/21 13:47:58 goose: up to current file version: 28692026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.68ms)8702026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000008712026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.4ms)8722026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.74ms)8732026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.57ms)8742026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000008752026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.49ms)8762026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.24ms)8772026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.53ms)8782026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000008792026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.68ms)8802026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.55ms)8812026/09/21 13:47:58 goose: up to current file version: 28822026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.39ms)8832026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000008842026/09/21 13:47:58 OK 20260905000000_add_claims.sql (7.61ms)8852026-09-21 13:47:58.714 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368862026-09-21 13:47:58.714 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8872026-09-21 13:47:58.714 UTC [459] ERROR: relation "goose_db_version" does not exist at character 368882026-09-21 13:47:58.714 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8892026-09-21 13:47:58.714 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368902026-09-21 13:47:58.714 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.45ms)8922026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.34ms)8932026/09/21 13:47:58 goose: up to current file version: 28942026-09-21 13:47:58.715 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368952026-09-21 13:47:58.715 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.55ms)8972026-09-21 13:47:58.717 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368982026-09-21 13:47:58.717 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026-09-21 13:47:58.717 UTC [464] ERROR: relation "goose_db_version" does not exist at character 369002026-09-21 13:47:58.717 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.57ms)9022026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000009032026/09/21 13:47:58 OK 2_object_stats_trigger.sql (3.89ms)9042026/09/21 13:47:58 goose: up to current file version: 29052026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.31ms)9062026/09/21 13:47:58 goose: up to current file version: 29072026-09-21 13:47:58.719 UTC [465] ERROR: relation "goose_db_version" does not exist at character 369082026-09-21 13:47:58.719 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026-09-21 13:47:58.719 UTC [466] ERROR: relation "goose_db_version" does not exist at character 369102026-09-21 13:47:58.719 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9112026-09-21 13:47:58.719 UTC [467] ERROR: relation "goose_db_version" does not exist at character 369122026-09-21 13:47:58.719 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026-09-21 13:47:58.720 UTC [468] ERROR: relation "goose_db_version" does not exist at character 369142026-09-21 13:47:58.720 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026-09-21 13:47:58.721 UTC [469] ERROR: relation "goose_db_version" does not exist at character 369162026-09-21 13:47:58.721 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026-09-21 13:47:58.722 UTC [471] ERROR: relation "goose_db_version" does not exist at character 369182026-09-21 13:47:58.722 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026-09-21 13:47:58.722 UTC [472] ERROR: relation "goose_db_version" does not exist at character 369202026-09-21 13:47:58.722 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.57ms)9222026-09-21 13:47:58.724 UTC [473] ERROR: relation "goose_db_version" does not exist at character 369232026-09-21 13:47:58.724 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026-09-21 13:47:58.725 UTC [470] ERROR: relation "goose_db_version" does not exist at character 369252026-09-21 13:47:58.725 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9262026/09/21 13:47:58 OK 2_object_stats_trigger.sql (3.12ms)9272026/09/21 13:47:58 goose: up to current file version: 29282026-09-21 13:47:58.734 UTC [474] ERROR: relation "goose_db_version" does not exist at character 369292026-09-21 13:47:58.734 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026/09/21 13:47:58 OK 20241026095416_initial_model.sql (15.07ms)9312026/09/21 13:47:58 OK 20241026095416_initial_model.sql (14.37ms)932--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.31s)933=== CONT TestClientSharedPathCommittedMidPush9342026/09/21 13:47:58 OK 20241026095416_initial_model.sql (17.15ms)9352026/09/21 13:47:58 OK 20241026095416_initial_model.sql (13.04ms)9362026/09/21 13:47:58 OK 20241026095416_initial_model.sql (16.7ms)9372026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.44ms)9382026/09/21 13:47:58 OK 20241026095416_initial_model.sql (15.33ms)9392026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)9402026/09/21 13:47:58 OK 20241026095416_initial_model.sql (15.18ms)9412026/09/21 13:47:58 OK 20241026095416_initial_model.sql (18.54ms)9422026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.64ms)9432026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.79ms)9442026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.73ms)9452026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)9462026/09/21 13:47:58 OK 20241026095416_initial_model.sql (18.89ms)9472026/09/21 13:47:58 OK 20251218171726_add_pins.sql (5.99ms)9482026/09/21 13:47:58 OK 20241026095416_initial_model.sql (18.82ms)9492026/09/21 13:47:58 OK 20241026095416_initial_model.sql (19.17ms)9502026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)9512026/09/21 13:47:58 OK 20251218171726_add_pins.sql (7.32ms)9522026/09/21 13:47:58 OK 20241026095416_initial_model.sql (22.29ms)9532026/09/21 13:47:58 OK 20241026095416_initial_model.sql (20.1ms)9542026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)9552026/09/21 13:47:58 OK 20241026095416_initial_model.sql (18.58ms)9562026-09-21 13:47:58.753 UTC [478] ERROR: relation "goose_db_version" does not exist at character 369572026-09-21 13:47:58.753 UTC [478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.06ms)9592026/09/21 13:47:58 OK 20251218171726_add_pins.sql (5.89ms)9602026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)9612026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.95ms)9622026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.98ms)9632026/09/21 13:47:58 OK 20251218171726_add_pins.sql (7.69ms)9642026/09/21 13:47:58 OK 20241026095416_initial_model.sql (20.37ms)9652026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.37ms)9662026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.17ms)9672026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.7ms)9682026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.4ms)9692026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (4.33ms)9702026/09/21 13:47:58 OK 20251218171726_add_pins.sql (7.66ms)9712026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)9722026/09/21 13:47:58 OK 20241026095416_initial_model.sql (12.39ms)9732026/09/21 13:47:58 OK 20251218171726_add_pins.sql (5.87ms)9742026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)9752026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)9762026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.12ms)9772026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.25ms)9782026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)9792026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)9802026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.27ms)9812026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.51ms)9822026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.77ms)9832026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.6ms)9842026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.64ms)9852026/09/21 13:47:58 OK 20251218171726_add_pins.sql (6.53ms)9862026/09/21 13:47:58 OK 20251218171726_add_pins.sql (8.28ms)9872026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.74ms)9882026/09/21 13:47:58 OK 20251218171726_add_pins.sql (5.56ms)9892026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.84ms)9902026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (8.25ms)9912026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.86ms)9922026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.67ms)9932026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.78ms)9942026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000009952026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.8ms)9962026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (7.66ms)9972026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.96ms)9982026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (7.84ms)9992026/09/21 13:47:58 OK 20251218171726_add_pins.sql (7.8ms)10002026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)10012026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (7.68ms)10022026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.41ms)10032026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010042026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.07ms)10052026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)10062026/09/21 13:47:58 OK 20260905000000_add_claims.sql (4.97ms)10072026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (7.06ms)10082026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (3.89ms)10092026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010102026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (3.96ms)10112026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010122026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.03ms)10132026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (7ms)10142026/09/21 13:47:58 OK 20241026095416_initial_model.sql (10.36ms)10152026/09/21 13:47:58 OK 20260905000000_add_claims.sql (4.93ms)10162026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (5.69ms)10172026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010182026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.72ms)10192026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010202026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (5.89ms)10212026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010222026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.38ms)10232026/09/21 13:47:58 OK 2_object_stats_trigger.sql (3.59ms)10242026/09/21 13:47:58 goose: up to current file version: 210252026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.22ms)10262026/09/21 13:47:58 OK 1_commit_pending_closure.sql (5.86ms)10272026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.13ms)10282026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.39ms)10292026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.64ms)10302026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (6.23ms)10312026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (6.01ms)10322026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010332026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.27ms)10342026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.39ms)10352026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)10362026/09/21 13:47:58 OK 20260905000000_add_claims.sql (4.67ms)10372026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (2.89ms)10382026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010392026/09/21 13:47:58 OK 2_object_stats_trigger.sql (1.52ms)10402026/09/21 13:47:58 goose: up to current file version: 210412026/09/21 13:47:58 OK 1_commit_pending_closure.sql (2.45ms)10422026/09/21 13:47:58 OK 1_commit_pending_closure.sql (3.49ms)10432026/09/21 13:47:58 OK 1_commit_pending_closure.sql (3.34ms)10442026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.08ms)10452026/09/21 13:47:58 goose: up to current file version: 210462026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.31ms)10472026/09/21 13:47:58 goose: up to current file version: 210482026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (4.55ms)10492026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010502026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (5.86ms)10512026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010522026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (5.61ms)10532026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010542026/09/21 13:47:58 OK 2_object_stats_trigger.sql (5.54ms)10552026/09/21 13:47:58 goose: up to current file version: 210562026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.06ms)10572026/09/21 13:47:58 goose: up to current file version: 210582026/09/21 13:47:58 OK 1_commit_pending_closure.sql (5.94ms)10592026/09/21 13:47:58 OK 1_commit_pending_closure.sql (6.61ms)10602026/09/21 13:47:58 OK 20260905000000_add_claims.sql (6.67ms)10612026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.65ms)10622026/09/21 13:47:58 goose: up to current file version: 210632026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (7.93ms)10642026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010652026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (7.21ms)10662026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010672026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (7.48ms)10682026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010692026/09/21 13:47:58 OK 20251218171726_add_pins.sql (7.79ms)10702026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.19ms)10712026/09/21 13:47:58 OK 1_commit_pending_closure.sql (3.99ms)10722026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.71ms)10732026/09/21 13:47:58 goose: up to current file version: 210742026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.13ms)10752026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.27ms)10762026/09/21 13:47:58 goose: up to current file version: 210772026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (5.23ms)10782026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000010792026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.8ms)10802026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.7ms)10812026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.72ms)10822026/09/21 13:47:58 goose: up to current file version: 210832026/09/21 13:47:58 goose: up to current file version: 210842026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.93ms)10852026/09/21 13:47:58 goose: up to current file version: 210862026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.53ms)10872026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.6ms)10882026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)10892026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.24ms)10902026/09/21 13:47:58 goose: up to current file version: 210912026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.91ms)10922026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.91ms)10932026/09/21 13:47:58 goose: up to current file version: 210942026/09/21 13:47:58 OK 2_object_stats_trigger.sql (4.54ms)10952026/09/21 13:47:58 goose: up to current file version: 210962026/09/21 13:47:58 OK 20260905000000_add_claims.sql (5.74ms)10972026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.72ms)10982026/09/21 13:47:58 goose: up to current file version: 210992026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (2.83ms)11002026/09/21 13:47:58 goose: successfully migrated database to version: 202609200000001101--- PASS: TestReadRedirectNar (0.37s)1102=== CONT TestClientWithDependencies11032026/09/21 13:47:58 OK 1_commit_pending_closure.sql (4.14ms)11042026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.25ms)11052026/09/21 13:47:58 goose: up to current file version: 211062026/09/21 13:47:58 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1107--- PASS: TestService_AuthMiddleware (0.38s)1108=== CONT TestClientMultipleUploads11092026-09-21 13:47:58.836 UTC [485] ERROR: relation "goose_db_version" does not exist at character 3611102026-09-21 13:47:58.836 UTC [485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11112026/09/21 13:47:58 OK 20241026095416_initial_model.sql (11.64ms)11122026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)11132026/09/21 13:47:58 OK 20251218171726_add_pins.sql (3.72ms)11142026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)11152026/09/21 13:47:58 OK 20260905000000_add_claims.sql (3.66ms)11162026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (2.66ms)11172026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000011182026/09/21 13:47:58 OK 1_commit_pending_closure.sql (2.51ms)11192026-09-21 13:47:58.883 UTC [486] ERROR: relation "goose_db_version" does not exist at character 3611202026-09-21 13:47:58.883 UTC [486] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11212026/09/21 13:47:58 OK 2_object_stats_trigger.sql (1.39ms)11222026/09/21 13:47:58 goose: up to current file version: 211232026-09-21 13:47:58.893 UTC [487] ERROR: relation "goose_db_version" does not exist at character 3611242026-09-21 13:47:58.893 UTC [487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1125--- PASS: TestReadRedirectUsesPublicS3URL (0.47s)1126=== CONT TestClientIntegration11272026/09/21 13:47:58 OK 20241026095416_initial_model.sql (10.46ms)11282026/09/21 13:47:58 INFO Received uploads request method=POST path=/api/pending_closures11292026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)11302026/09/21 13:47:58 OK 20251218171726_add_pins.sql (3.85ms)11312026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)11322026/09/21 13:47:58 OK 20241026095416_initial_model.sql (9.31ms)11332026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)11342026/09/21 13:47:58 OK 20260905000000_add_claims.sql (3.69ms)11352026/09/21 13:47:58 OK 20251218171726_add_pins.sql (3.9ms)11362026/09/21 13:47:58 INFO Received uploads request method=POST path=/api/pending_closures11372026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (3.72ms)11382026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000011392026/09/21 13:47:58 OK 1_commit_pending_closure.sql (2.59ms)11402026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)11412026/09/21 13:47:58 OK 2_object_stats_trigger.sql (1.98ms)11422026/09/21 13:47:58 goose: up to current file version: 211432026/09/21 13:47:58 OK 20260905000000_add_claims.sql (4.07ms)11442026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (3.12ms)11452026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000011462026/09/21 13:47:58 OK 1_commit_pending_closure.sql (3.01ms)11472026/09/21 13:47:58 OK 2_object_stats_trigger.sql (2.03ms)11482026/09/21 13:47:58 goose: up to current file version: 211492026-09-21 13:47:58.968 UTC [490] ERROR: relation "goose_db_version" does not exist at character 3611502026-09-21 13:47:58.968 UTC [490] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026/09/21 13:47:58 OK 20241026095416_initial_model.sql (9.66ms)11522026/09/21 13:47:58 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)11532026/09/21 13:47:58 OK 20251218171726_add_pins.sql (2.91ms)11542026/09/21 13:47:58 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)11552026/09/21 13:47:58 OK 20260905000000_add_claims.sql (2.34ms)11562026/09/21 13:47:58 OK 20260920000000_drop_claims.sql (1.76ms)11572026/09/21 13:47:58 goose: successfully migrated database to version: 2026092000000011582026/09/21 13:47:58 OK 1_commit_pending_closure.sql (1.8ms)11592026/09/21 13:47:58 OK 2_object_stats_trigger.sql (767.41µs)11602026/09/21 13:47:58 goose: up to current file version: 21161--- PASS: TestReadProxyNarStreaming (0.66s)1162=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11632026/09/21 13:47:59 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/21 13:47:59 INFO Received cleanup request method=DELETE path=/api/pending_closures11652026/09/21 13:47:59 INFO Aborted multipart uploads count=011662026/09/21 13:47:59 INFO Received uploads request method=POST path=/api/pending_closures11672026/09/21 13:47:59 INFO Received cleanup request method=DELETE path=/api/pending_closures11682026/09/21 13:47:59 INFO Aborted multipart uploads count=111692026/09/21 13:47:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11702026-09-21 13:47:59.163 UTC [493] ERROR: relation "goose_db_version" does not exist at character 3611712026-09-21 13:47:59.163 UTC [493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11722026-09-21 13:47:59.164 UTC [461] ERROR: Closure does not exist: id=111732026-09-21 13:47:59.164 UTC [461] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11742026-09-21 13:47:59.164 UTC [461] STATEMENT: -- name: CommitPendingClosure :exec1175 SELECT commit_pending_closure($1::bigint)1176 1177--- PASS: TestService_cleanupPendingClosuresHandler (0.73s)1178=== CONT TestGracefulShutdownDrainsInflight11792026/09/21 13:47:59 INFO Received uploads request method=POST path=/api/pending_closures11802026/09/21 13:47:59 INFO Received uploads request method=POST path=/api/pending_closures11812026/09/21 13:47:59 INFO Starting HTTP server address=127.0.0.1:4482111822026/09/21 13:47:59 INFO Received uploads request method=POST path=/api/pending_closures11832026/09/21 13:47:59 INFO Shutdown signal received, draining in-flight requests timeout=10s11842026/09/21 13:47:59 OK 20241026095416_initial_model.sql (11.56ms)11852026/09/21 13:47:59 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)11862026/09/21 13:47:59 OK 20251218171726_add_pins.sql (3.83ms)11872026/09/21 13:47:59 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)11882026/09/21 13:47:59 OK 20260905000000_add_claims.sql (2.94ms)11892026/09/21 13:47:59 OK 20260920000000_drop_claims.sql (2.22ms)11902026/09/21 13:47:59 goose: successfully migrated database to version: 2026092000000011912026/09/21 13:47:59 OK 1_commit_pending_closure.sql (2.03ms)11922026/09/21 13:47:59 OK 2_object_stats_trigger.sql (997.53µs)11932026/09/21 13:47:59 goose: up to current file version: 21194--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1195=== CONT TestService_NativeMTLS11962026-09-21 13:47:59.348 UTC [496] ERROR: relation "goose_db_version" does not exist at character 3611972026-09-21 13:47:59.348 UTC [496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11982026/09/21 13:47:59 OK 20241026095416_initial_model.sql (41.68ms)11992026/09/21 13:47:59 OK 20251210153512_drop_unused_gin_index.sql (4.49ms)12002026/09/21 13:47:59 OK 20251218171726_add_pins.sql (7.64ms)12012026/09/21 13:47:59 OK 20260628120000_add_object_size_and_stats.sql (6.39ms)12022026/09/21 13:47:59 OK 20260905000000_add_claims.sql (9.81ms)12032026/09/21 13:47:59 OK 20260920000000_drop_claims.sql (9.12ms)12042026/09/21 13:47:59 goose: successfully migrated database to version: 202609200000001205--- PASS: TestGCBugBareHashReferences (1.01s)1206=== CONT TestMetricsInventory12072026/09/21 13:47:59 OK 1_commit_pending_closure.sql (9.53ms)12082026/09/21 13:47:59 OK 2_object_stats_trigger.sql (5.28ms)12092026/09/21 13:47:59 goose: up to current file version: 212102026-09-21 13:47:59.532 UTC [499] ERROR: relation "goose_db_version" does not exist at character 3612112026-09-21 13:47:59.532 UTC [499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12122026/09/21 13:47:59 OK 20241026095416_initial_model.sql (12.28ms)12132026/09/21 13:47:59 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)12142026/09/21 13:47:59 OK 20251218171726_add_pins.sql (3.95ms)12152026/09/21 13:47:59 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)12162026/09/21 13:47:59 OK 20260905000000_add_claims.sql (4.38ms)12172026/09/21 13:47:59 OK 20260920000000_drop_claims.sql (2.04ms)12182026/09/21 13:47:59 goose: successfully migrated database to version: 2026092000000012192026/09/21 13:47:59 OK 1_commit_pending_closure.sql (2.04ms)12202026/09/21 13:47:59 OK 2_object_stats_trigger.sql (879.27µs)12212026/09/21 13:47:59 goose: up to current file version: 21222--- PASS: TestReadProxyDisabled (1.45s)1223=== CONT TestNARDeduplicationMetadataUploadBug1224--- PASS: TestReadProxyNarinfo (1.42s)1225=== CONT TestCreatePendingClosureRejectsOversizedNAR12262026/09/21 13:47:59 INFO Received uploads request method=POST path=/api/pending_closures1227--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1228=== CONT TestCacheConfigHandlerMaxNarSize1229--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1230=== CONT TestGenerateLandingPage1231--- PASS: TestGenerateLandingPage (0.01s)1232=== CONT TestService_readinessHandler12332026-09-21 13:47:59.954 UTC [504] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-21 13:47:59.954 UTC [504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/09/21 13:47:59 OK 20241026095416_initial_model.sql (16.67ms)12362026/09/21 13:47:59 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)12372026/09/21 13:47:59 OK 20251218171726_add_pins.sql (4.3ms)12382026/09/21 13:47:59 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)12392026/09/21 13:47:59 OK 20260905000000_add_claims.sql (2.9ms)12402026/09/21 13:47:59 OK 20260920000000_drop_claims.sql (2.38ms)12412026/09/21 13:47:59 goose: successfully migrated database to version: 2026092000000012422026/09/21 13:47:59 OK 1_commit_pending_closure.sql (1.95ms)12432026/09/21 13:47:59 OK 2_object_stats_trigger.sql (978.85µs)12442026/09/21 13:47:59 goose: up to current file version: 212452026-09-21 13:48:00.000 UTC [505] ERROR: relation "goose_db_version" does not exist at character 3612462026-09-21 13:48:00.000 UTC [505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12472026/09/21 13:48:00 OK 20241026095416_initial_model.sql (13.14ms)12482026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)12492026/09/21 13:48:00 OK 20251218171726_add_pins.sql (3.68ms)12502026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (2.98ms)12512026/09/21 13:48:00 OK 20260905000000_add_claims.sql (3.64ms)12522026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (2.38ms)12532026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000012542026/09/21 13:48:00 OK 1_commit_pending_closure.sql (2.03ms)1255--- PASS: TestReadProxyRangeRequest (1.60s)1256=== CONT TestService_healthCheckHandler12572026/09/21 13:48:00 OK 2_object_stats_trigger.sql (2.52ms)12582026/09/21 13:48:00 goose: up to current file version: 212592026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures12602026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures1261--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.67s)1262=== CONT TestReadProxyHead12632026-09-21 13:48:00.106 UTC [508] ERROR: relation "goose_db_version" does not exist at character 3612642026-09-21 13:48:00.106 UTC [508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12652026/09/21 13:48:00 INFO lead: acquired remote=192.0.2.1:123412662026/09/21 13:48:00 INFO lead: released remote=192.0.2.1:12341267--- PASS: TestLeadEndsOnShutdown (1.62s)1268=== CONT TestReadProxyConditionalGet12692026/09/21 13:48:00 OK 20241026095416_initial_model.sql (11.11ms)12702026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)12712026/09/21 13:48:00 OK 20251218171726_add_pins.sql (5.29ms)12722026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)12732026/09/21 13:48:00 OK 20260905000000_add_claims.sql (4.14ms)12742026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (3.66ms)12752026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000012762026/09/21 13:48:00 OK 1_commit_pending_closure.sql (3.72ms)12772026/09/21 13:48:00 OK 2_object_stats_trigger.sql (2.48ms)12782026/09/21 13:48:00 goose: up to current file version: 212792026-09-21 13:48:00.180 UTC [513] ERROR: relation "goose_db_version" does not exist at character 3612802026-09-21 13:48:00.180 UTC [513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12812026-09-21 13:48:00.205 UTC [515] ERROR: relation "goose_db_version" does not exist at character 3612822026-09-21 13:48:00.205 UTC [515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12832026/09/21 13:48:00 OK 20241026095416_initial_model.sql (18.22ms)12842026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)12852026/09/21 13:48:00 INFO lead: acquired remote=192.0.2.1:123412862026/09/21 13:48:00 OK 20251218171726_add_pins.sql (4.95ms)12872026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)12882026/09/21 13:48:00 OK 20241026095416_initial_model.sql (12.35ms)12892026/09/21 13:48:00 OK 20260905000000_add_claims.sql (3.11ms)12902026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)12912026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (1.94ms)12922026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000012932026/09/21 13:48:00 OK 20251218171726_add_pins.sql (3.9ms)12942026/09/21 13:48:00 OK 1_commit_pending_closure.sql (3.28ms)12952026/09/21 13:48:00 OK 2_object_stats_trigger.sql (1.09ms)12962026/09/21 13:48:00 goose: up to current file version: 212972026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)12982026/09/21 13:48:00 OK 20260905000000_add_claims.sql (2.8ms)12992026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (1.99ms)13002026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000013012026/09/21 13:48:00 OK 1_commit_pending_closure.sql (2.97ms)13022026/09/21 13:48:00 OK 2_object_stats_trigger.sql (953.79µs)13032026/09/21 13:48:00 goose: up to current file version: 213042026/09/21 13:48:00 INFO lead: released remote=192.0.2.1:123413052026/09/21 13:48:00 INFO lead: acquired remote=192.0.2.1:123413062026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures13072026/09/21 13:48:00 INFO lead: released remote=192.0.2.1:12341308--- PASS: TestLeadElectsOneAndHandsOver (1.92s)1309=== CONT TestReadProxyInvalidPath13102026-09-21 13:48:00.500 UTC [520] ERROR: relation "goose_db_version" does not exist at character 3613112026-09-21 13:48:00.500 UTC [520] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13122026/09/21 13:48:00 OK 20241026095416_initial_model.sql (9.47ms)13132026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)13142026/09/21 13:48:00 OK 20251218171726_add_pins.sql (3.48ms)13152026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)13162026/09/21 13:48:00 OK 20260905000000_add_claims.sql (3.47ms)13172026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (1.84ms)13182026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000013192026/09/21 13:48:00 OK 1_commit_pending_closure.sql (1.95ms)13202026/09/21 13:48:00 OK 2_object_stats_trigger.sql (902.29µs)13212026/09/21 13:48:00 goose: up to current file version: 213222026/09/21 13:48:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13232026/09/21 13:48:00 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1324--- PASS: TestCompleteMultipartUnregistered (2.16s)1325=== CONT TestReadRedirectKeepsNarinfoProxied13262026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/21 13:48:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13282026/09/21 13:48:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13292026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures1330--- PASS: TestService_Rustfstest (2.21s)1331--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.21s)1332=== CONT TestGCTaskStore_Fail1333--- PASS: TestGCTaskStore_Fail (0.00s)1334=== CONT TestGCTaskStore_PhaseUpdates1335--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1336=== CONT TestGCTaskStore_GetEmpty1337--- PASS: TestGCTaskStore_GetEmpty (0.00s)1338=== CONT TestGCTaskStore_CompletedAllowsNewTask1339--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1340=== CONT TestOrphanedObjectsGCStressTest1341=== CONT TestReadProxy40413422026/09/21 13:48:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13432026-09-21 13:48:00.662 UTC [525] ERROR: relation "goose_db_version" does not exist at character 3613442026-09-21 13:48:00.662 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13452026/09/21 13:48:00 OK 20241026095416_initial_model.sql (13.5ms)13462026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)13472026/09/21 13:48:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWZkMWY2ZTAtYmMxMy00OTg0LWI0MTAtMmFkNzgzNzcwMGUzLmM1ZGZmNmM5LTJmYzQtNDZhOS1hNDUxLTFjZWY2NGI0N2QwZngxNzg5OTk4NDc5MTc3NDc1ODcz parts=1013482026/09/21 13:48:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1349--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.19s)1350=== CONT TestObjectStatsTrigger13512026/09/21 13:48:00 OK 20251218171726_add_pins.sql (4.19ms)13522026/09/21 13:48:00 INFO Completed upload id=113532026/09/21 13:48:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013542026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures13552026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)13562026/09/21 13:48:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures13572026/09/21 13:48:00 OK 20260905000000_add_claims.sql (3.66ms)13582026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (2.93ms)13592026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000013602026/09/21 13:48:00 OK 1_commit_pending_closure.sql (2.85ms)13612026/09/21 13:48:00 OK 2_object_stats_trigger.sql (2.01ms)13622026/09/21 13:48:00 goose: up to current file version: 213632026/09/21 13:48:00 INFO Aborted multipart uploads count=013642026/09/21 13:48:00 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=013652026-09-21 13:48:00.736 UTC [550] ERROR: relation "goose_db_version" does not exist at character 3613662026-09-21 13:48:00.736 UTC [550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13672026-09-21 13:48:00.737 UTC [551] ERROR: relation "goose_db_version" does not exist at character 3613682026-09-21 13:48:00.737 UTC [551] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13692026/09/21 13:48:00 INFO Vacuumed table table=pending_closures13702026/09/21 13:48:00 INFO Vacuumed table table=pending_objects13712026/09/21 13:48:00 INFO Vacuumed table table=multipart_uploads13722026/09/21 13:48:00 INFO Vacuumed table table=closures13732026/09/21 13:48:00 OK 20241026095416_initial_model.sql (10.43ms)13742026/09/21 13:48:00 OK 20241026095416_initial_model.sql (11.63ms)13752026/09/21 13:48:00 INFO Vacuumed table table=objects13762026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)13772026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (4.22ms)13782026/09/21 13:48:00 OK 20251218171726_add_pins.sql (4ms)13792026/09/21 13:48:00 OK 20251218171726_add_pins.sql (3.62ms)13802026/09/21 13:48:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13812026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)13822026/09/21 13:48:00 OK 20260905000000_add_claims.sql (3.45ms)13832026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)13842026-09-21 13:48:00.769 UTC [552] ERROR: relation "goose_db_version" does not exist at character 3613852026-09-21 13:48:00.769 UTC [552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13862026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (2.71ms)13872026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000013882026/09/21 13:48:00 OK 20260905000000_add_claims.sql (4.44ms)13892026/09/21 13:48:00 OK 1_commit_pending_closure.sql (2.51ms)13902026/09/21 13:48:00 OK 2_object_stats_trigger.sql (1.05ms)13912026/09/21 13:48:00 goose: up to current file version: 213922026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (2.19ms)13932026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000013942026/09/21 13:48:00 OK 1_commit_pending_closure.sql (3.23ms)13952026/09/21 13:48:00 OK 2_object_stats_trigger.sql (2.1ms)13962026/09/21 13:48:00 goose: up to current file version: 213972026/09/21 13:48:00 OK 20241026095416_initial_model.sql (9.75ms)13982026/09/21 13:48:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWZkMWY2ZTAtYmMxMy00OTg0LWI0MTAtMmFkNzgzNzcwMGUzLjNhODBlODQzLTAwNzAtNDBiMy1hMThiLTg2NTY3MWMzM2VkZngxNzg5OTk4NDc5MTE2ODUwNjE5 parts=1213992026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)14002026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures14012026/09/21 13:48:00 OK 20251218171726_add_pins.sql (5.88ms)1402--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.36s)1403=== CONT TestMultipartCleanup14042026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)14052026/09/21 13:48:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014062026/09/21 13:48:00 OK 20260905000000_add_claims.sql (5.21ms)1407--- PASS: TestService_createPendingClosureHandler (2.37s)1408=== CONT TestGCTaskStore_GetReturnsLatest1409--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1410=== CONT TestOrphanedObjectsGC14112026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (2.02ms)14122026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000014132026/09/21 13:48:00 OK 1_commit_pending_closure.sql (2.09ms)14142026/09/21 13:48:00 OK 2_object_stats_trigger.sql (862.25µs)14152026/09/21 13:48:00 goose: up to current file version: 214162026/09/21 13:48:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14172026-09-21 13:48:00.875 UTC [557] ERROR: relation "goose_db_version" does not exist at character 3614182026-09-21 13:48:00.875 UTC [557] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14192026/09/21 13:48:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWZkMWY2ZTAtYmMxMy00OTg0LWI0MTAtMmFkNzgzNzcwMGUzLjY2YzMxNmJjLWRkZWYtNDA1Ni1iZDNhLWYyMGNlMzBlNzAwNXgxNzg5OTk4NDc4OTA4NjgxOTk0 parts=1214202026-09-21 13:48:00.885 UTC [559] ERROR: relation "goose_db_version" does not exist at character 3614212026-09-21 13:48:00.885 UTC [559] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1422--- PASS: TestRedundantMultipartUpload (2.46s)1423=== CONT TestGCTaskStore_DeduplicateSameParams1424--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1425=== CONT TestGCTaskStore_ConflictDifferentParams1426--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1427=== CONT TestService_RequireScope_OIDC14282026/09/21 13:48:00 OK 20241026095416_initial_model.sql (10.12ms)14292026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)14302026/09/21 13:48:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44207/oidc14312026/09/21 13:48:00 OK 20251218171726_add_pins.sql (4.33ms)1432--- PASS: TestResurrectedObjectNotDeleted (2.40s)1433=== CONT TestGCTaskStore_StartNew1434--- PASS: TestGCTaskStore_StartNew (0.00s)1435=== CONT TestClientCADerivations14362026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (5.75ms)14372026/09/21 13:48:00 OK 20241026095416_initial_model.sql (11.94ms)14382026/09/21 13:48:00 OK 20251210153512_drop_unused_gin_index.sql (5.9ms)14392026/09/21 13:48:00 OK 20260905000000_add_claims.sql (6.37ms)14402026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (2.58ms)14412026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000014422026/09/21 13:48:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14432026/09/21 13:48:00 OK 20251218171726_add_pins.sql (5.65ms)14442026/09/21 13:48:00 OK 1_commit_pending_closure.sql (3.97ms)14452026/09/21 13:48:00 OK 2_object_stats_trigger.sql (1.29ms)14462026/09/21 13:48:00 goose: up to current file version: 214472026/09/21 13:48:00 OK 20260628120000_add_object_size_and_stats.sql (11.99ms)14482026/09/21 13:48:00 OK 20260905000000_add_claims.sql (7.07ms)14492026/09/21 13:48:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWZkMWY2ZTAtYmMxMy00OTg0LWI0MTAtMmFkNzgzNzcwMGUzLjM0ZmI3Yzc2LWY4ZDQtNDM5Yy04MWY0LWQ5NzE0NjBiMzIwZXgxNzg5OTk4NDgwMDczMTg3ODY5 parts=1014502026/09/21 13:48:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14512026/09/21 13:48:00 OK 20260920000000_drop_claims.sql (3.46ms)14522026/09/21 13:48:00 goose: successfully migrated database to version: 2026092000000014532026/09/21 13:48:00 OK 1_commit_pending_closure.sql (7.7ms)14542026/09/21 13:48:00 INFO Completed upload id=114552026/09/21 13:48:00 OK 2_object_stats_trigger.sql (2.48ms)14562026/09/21 13:48:00 goose: up to current file version: 214572026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures14582026/09/21 13:48:00 INFO Received uploads request method=POST path=/api/pending_closures14592026/09/21 13:48:00 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14602026/09/21 13:48:00 WARN Found objects in DB but missing from S3, will re-upload count=11461--- PASS: TestService_verifyS3Integrity (2.53s)1462=== CONT TestService_ReadAuthMiddleware1463=== NAME TestPinProtectsFromGC1464 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2863902755/001/store/hb9g8ja3k5galp0h5rg25i6xrlwqzlih-pinned-file.txt1465 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2863902755/001/store/93d4fig1iq1nc53x5bi1av0imsjb1g62-unpinned-file.txt14662026-09-21 13:48:00.991 UTC [619] ERROR: relation "goose_db_version" does not exist at character 3614672026-09-21 13:48:00.991 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14682026-09-21 13:48:00.995 UTC [620] ERROR: relation "goose_db_version" does not exist at character 3614692026-09-21 13:48:00.995 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1470=== NAME TestClientMultipleUploads14712026/09/21 13:48:01 OK 20241026095416_initial_model.sql (11.13ms)1472 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2500769662/001/store/fr8kzkbbii68wfiavg39314f7398y9m7-test-file-0.txt14732026/09/21 13:48:01 OK 20241026095416_initial_model.sql (10.79ms)14742026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)14752026-09-21 13:48:01.148 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3614762026-09-21 13:48:01.148 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14772026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)14782026/09/21 13:48:01 OK 20251218171726_add_pins.sql (24.45ms)14792026/09/21 13:48:01 OK 20251218171726_add_pins.sql (25.83ms)1480 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2500769662/001/store/cn5dj7vydl4ydwn6l14mhr0qn61gvyw6-test-file-1.txt14812026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)14822026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (6.6ms)14832026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14842026/09/21 13:48:01 OK 20260905000000_add_claims.sql (6.02ms)14852026/09/21 13:48:01 OK 20241026095416_initial_model.sql (11.32ms)14862026/09/21 13:48:01 OK 20260905000000_add_claims.sql (5.51ms)14872026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)14882026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (3.63ms)14892026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000014902026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (3.67ms)14912026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000014922026/09/21 13:48:01 OK 20251218171726_add_pins.sql (3.24ms)14932026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.83ms)14942026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.95ms)14952026/09/21 13:48:01 OK 2_object_stats_trigger.sql (1.77ms)14962026/09/21 13:48:01 goose: up to current file version: 214972026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)14982026/09/21 13:48:01 OK 2_object_stats_trigger.sql (1.59ms)14992026/09/21 13:48:01 goose: up to current file version: 21500=== NAME TestClientWithDependencies1501 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2063369595/001/store/qwhgvr1l9y3fkxgck7abkqqrf35nnkzb-test-script15022026/09/21 13:48:01 OK 20260905000000_add_claims.sql (4.33ms)15032026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (2.35ms)15042026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000015052026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.24ms)15062026/09/21 13:48:01 OK 2_object_stats_trigger.sql (981.17µs)15072026/09/21 13:48:01 goose: up to current file version: 215082026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15092026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1510=== NAME TestClientMultipleUploads1511 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2500769662/001/store/dyl7dlxcphll6iya9m8rpjr1wwqdd4w9-test-file-2.txt15122026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures1513=== NAME TestClientIntegration1514 client_integration_test.go:286: Created store path: /build/TestClientIntegration2370810505/002/store/z978yxibw07ryvjsbb8jgc6k9bqhvpyj-test-file.txt15152026/09/21 13:48:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15162026/09/21 13:48:01 INFO Uploading hb9g8ja3k5galp0h5rg25i6xrlwqzlih-pinned-file.txt (128B)1517=== NAME TestClientWithDependencies1518 client_integration_test.go:615: Found 1 dependencies (including self)15192026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15202026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15212026/09/21 13:48:01 WARN Failed to register uploaded object key=hb9g8ja3k5galp0h5rg25i6xrlwqzlih.ls error="server returned 404: 404 page not found\n"15222026/09/21 13:48:01 INFO Signed narinfos id=1 count=115232026/09/21 13:48:01 INFO Uploading 1 narinfos15242026/09/21 13:48:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15252026/09/21 13:48:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1526--- PASS: TestService_NativeMTLS (2.00s)1527=== CONT TestCacheConfigHandler1528=== RUN TestCacheConfigHandler/full_config,_no_issuer1529=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1530=== RUN TestCacheConfigHandler/no_cache_url_configured1531=== PAUSE TestCacheConfigHandler/no_cache_url_configured1532=== RUN TestCacheConfigHandler/no_signing_keys1533=== PAUSE TestCacheConfigHandler/no_signing_keys1534=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1535=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1536=== CONT TestService_ReadScope_PublicByDefault15372026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15382026/09/21 13:48:01 WARN Failed to register uploaded object key=hb9g8ja3k5galp0h5rg25i6xrlwqzlih.narinfo error="server returned 404: 404 page not found\n"15392026/09/21 13:48:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15402026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15412026/09/21 13:48:01 INFO Completed upload id=115422026/09/21 13:48:01 INFO Upload complete. (105ms)15432026/09/21 13:48:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWZkMWY2ZTAtYmMxMy00OTg0LWI0MTAtMmFkNzgzNzcwMGUzLjYyMDI1NTE5LWE4M2ItNDYzMC05ZTRlLTljOTVmMGVmMDViZngxNzg5OTk4NDgxMjE4NjU2NjI515442026/09/21 13:48:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWZkMWY2ZTAtYmMxMy00OTg0LWI0MTAtMmFkNzgzNzcwMGUzLjYyMDI1NTE5LWE4M2ItNDYzMC05ZTRlLTljOTVmMGVmMDViZngxNzg5OTk4NDgxMjE4NjU2NjI5 parts=11545--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.17s)1546=== CONT TestService_AuthMiddleware_OIDC15472026/09/21 13:48:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43885/oidc15482026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15492026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15502026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures1551--- PASS: TestMetricsInventory (1.87s)1552=== CONT TestCacheStatsHandler15532026/09/21 13:48:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15542026/09/21 13:48:01 INFO Uploading qwhgvr1l9y3fkxgck7abkqqrf35nnkzb-test-script (136B)15552026-09-21 13:48:01.316 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 3615562026-09-21 13:48:01.316 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15572026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15582026/09/21 13:48:01 WARN Failed to register uploaded object key=log/382aphw3abdva7q52v2x9mh8axbmfqkd-test-script.drv error="server returned 404: 404 page not found\n"15592026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15602026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15612026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15622026/09/21 13:48:01 WARN Failed to register uploaded object key=qwhgvr1l9y3fkxgck7abkqqrf35nnkzb.ls error="server returned 404: 404 page not found\n"15632026/09/21 13:48:01 INFO Signed narinfos id=1 count=115642026/09/21 13:48:01 INFO Uploading 1 narinfos15652026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15662026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15672026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15682026/09/21 13:48:01 WARN Failed to register uploaded object key=qwhgvr1l9y3fkxgck7abkqqrf35nnkzb.narinfo error="server returned 404: 404 page not found\n"15692026-09-21 13:48:01.334 UTC [1077] ERROR: relation "goose_db_version" does not exist at character 3615702026-09-21 13:48:01.334 UTC [1077] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15712026/09/21 13:48:01 OK 20241026095416_initial_model.sql (13.8ms)15722026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)15732026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15742026/09/21 13:48:01 INFO Completed upload id=115752026/09/21 13:48:01 INFO Upload complete. (78ms)15762026/09/21 13:48:01 OK 20251218171726_add_pins.sql (5.02ms)15772026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures1578=== NAME TestClientWithDependencies1579 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2063369595/001/store) requires matching store prefix15802026/09/21 13:48:01 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15812026/09/21 13:48:01 INFO Uploading dyl7dlxcphll6iya9m8rpjr1wwqdd4w9-test-file-2.txt (160B)15822026/09/21 13:48:01 INFO Uploading cn5dj7vydl4ydwn6l14mhr0qn61gvyw6-test-file-1.txt (160B)15832026/09/21 13:48:01 INFO Uploading fr8kzkbbii68wfiavg39314f7398y9m7-test-file-0.txt (160B)15842026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)1585--- PASS: TestClientWithDependencies (2.55s)1586=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15872026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15882026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15892026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15902026/09/21 13:48:01 OK 20260905000000_add_claims.sql (4.62ms)15912026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15922026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15932026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures15942026/09/21 13:48:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15952026/09/21 13:48:01 INFO Uploading 93d4fig1iq1nc53x5bi1av0imsjb1g62-unpinned-file.txt (128B)15962026/09/21 13:48:01 WARN Failed to register uploaded object key=dyl7dlxcphll6iya9m8rpjr1wwqdd4w9.ls error="server returned 404: 404 page not found\n"15972026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (5.33ms)15982026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000015992026/09/21 13:48:01 WARN Failed to register uploaded object key=fr8kzkbbii68wfiavg39314f7398y9m7.ls error="server returned 404: 404 page not found\n"16002026/09/21 13:48:01 WARN Failed to register uploaded object key=cn5dj7vydl4ydwn6l14mhr0qn61gvyw6.ls error="server returned 404: 404 page not found\n"16012026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16022026/09/21 13:48:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16032026/09/21 13:48:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16042026/09/21 13:48:01 INFO Uploading lpp67nx6g9a89l57s829xgin3xp3gmlb-shared-dep (136B)16052026/09/21 13:48:01 INFO Uploading z978yxibw07ryvjsbb8jgc6k9bqhvpyj-test-file.txt (152B)16062026/09/21 13:48:01 INFO Signed narinfos id=1 count=116072026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16082026/09/21 13:48:01 INFO Signed narinfos id=2 count=116092026/09/21 13:48:01 OK 20241026095416_initial_model.sql (19.2ms)16102026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16112026/09/21 13:48:01 INFO Signed narinfos id=3 count=116122026/09/21 13:48:01 INFO Uploading 3 narinfos16132026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16142026/09/21 13:48:01 OK 1_commit_pending_closure.sql (5.67ms)16152026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)16162026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16172026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16182026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16192026/09/21 13:48:01 WARN Failed to register uploaded object key=93d4fig1iq1nc53x5bi1av0imsjb1g62.ls error="server returned 404: 404 page not found\n"16202026/09/21 13:48:01 WARN Failed to register uploaded object key=cn5dj7vydl4ydwn6l14mhr0qn61gvyw6.narinfo error="server returned 404: 404 page not found\n"16212026/09/21 13:48:01 INFO Signed narinfos id=2 count=116222026/09/21 13:48:01 INFO Uploading 1 narinfos16232026/09/21 13:48:01 OK 2_object_stats_trigger.sql (2.8ms)16242026/09/21 13:48:01 goose: up to current file version: 216252026/09/21 13:48:01 WARN Failed to register uploaded object key=dyl7dlxcphll6iya9m8rpjr1wwqdd4w9.narinfo error="server returned 404: 404 page not found\n"16262026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16272026/09/21 13:48:01 WARN Failed to register uploaded object key=fr8kzkbbii68wfiavg39314f7398y9m7.narinfo error="server returned 404: 404 page not found\n"16282026/09/21 13:48:01 OK 20251218171726_add_pins.sql (5.62ms)16292026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16302026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16312026/09/21 13:48:01 WARN Failed to register uploaded object key=z978yxibw07ryvjsbb8jgc6k9bqhvpyj.ls error="server returned 404: 404 page not found\n"16322026/09/21 13:48:01 INFO Signed narinfos id=1 count=116332026/09/21 13:48:01 INFO Uploading 1 narinfos16342026/09/21 13:48:01 INFO Signed narinfos id=2 count=116352026/09/21 13:48:01 WARN Failed to register uploaded object key=lpp67nx6g9a89l57s829xgin3xp3gmlb.ls error="server returned 404: 404 page not found\n"16362026/09/21 13:48:01 INFO Uploading 1 narinfos16372026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16382026/09/21 13:48:01 WARN Failed to register uploaded object key=93d4fig1iq1nc53x5bi1av0imsjb1g62.narinfo error="server returned 404: 404 page not found\n"16392026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16402026/09/21 13:48:01 WARN Failed to register uploaded object key=z978yxibw07ryvjsbb8jgc6k9bqhvpyj.narinfo error="server returned 404: 404 page not found\n"16412026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16422026/09/21 13:48:01 WARN Failed to register uploaded object key=lpp67nx6g9a89l57s829xgin3xp3gmlb.narinfo error="server returned 404: 404 page not found\n"16432026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (6.98ms)16442026/09/21 13:48:01 INFO Completed upload id=216452026/09/21 13:48:01 INFO Completed upload id=316462026/09/21 13:48:01 INFO Upload complete. (97ms)16472026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16482026-09-21 13:48:01.385 UTC [1132] ERROR: relation "goose_db_version" does not exist at character 3616492026-09-21 13:48:01.385 UTC [1132] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16502026/09/21 13:48:01 INFO Completed upload id=116512026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16522026/09/21 13:48:01 OK 20260905000000_add_claims.sql (6.77ms)16532026/09/21 13:48:01 INFO Completed upload id=116542026/09/21 13:48:01 INFO Upload complete. (109ms)16552026/09/21 13:48:01 INFO Completed upload id=216562026/09/21 13:48:01 INFO Completed upload id=216572026/09/21 13:48:01 INFO Upload complete. (132ms)16582026/09/21 13:48:01 INFO Upload complete. (98ms)1659=== NAME TestClientMultipleUploads16602026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures1661 client_integration_test.go:369: Uploaded 3 paths in 176.226432ms16622026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (5.15ms)16632026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000016642026/09/21 13:48:01 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16652026/09/21 13:48:01 INFO Uploading i7j0wwx2dd535hpg5a52smvzjafcqdy0-top (224B)16662026/09/21 13:48:01 INFO Uploading lpp67nx6g9a89l57s829xgin3xp3gmlb-shared-dep (136B)16672026/09/21 13:48:01 OK 1_commit_pending_closure.sql (3.73ms)16682026/09/21 13:48:01 OK 2_object_stats_trigger.sql (2.68ms)16692026/09/21 13:48:01 goose: up to current file version: 216702026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/1anyg8f958a4yh2i4frna4b7j1cr00x8wcwn026w69k6p4y6yby2.nar.zst error="server returned 404: 404 page not found\n"16712026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16722026/09/21 13:48:01 OK 20241026095416_initial_model.sql (11.23ms)1673--- PASS: TestClientMultipleUploads (2.60s)1674=== CONT TestGCMetrics16752026/09/21 13:48:01 WARN Failed to register uploaded object key=i7j0wwx2dd535hpg5a52smvzjafcqdy0.ls error="server returned 404: 404 page not found\n"16762026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16772026/09/21 13:48:01 WARN Failed to register uploaded object key=lpp67nx6g9a89l57s829xgin3xp3gmlb.ls error="server returned 404: 404 page not found\n"16782026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)16792026/09/21 13:48:01 INFO Signed narinfos id=3 count=116802026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16812026/09/21 13:48:01 INFO Signed narinfos id=1 count=116822026/09/21 13:48:01 INFO Uploading 2 narinfos16832026/09/21 13:48:01 OK 20251218171726_add_pins.sql (4.52ms)16842026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16852026/09/21 13:48:01 WARN Failed to register uploaded object key=i7j0wwx2dd535hpg5a52smvzjafcqdy0.narinfo error="server returned 404: 404 page not found\n"16862026/09/21 13:48:01 WARN Failed to register uploaded object key=lpp67nx6g9a89l57s829xgin3xp3gmlb.narinfo error="server returned 404: 404 page not found\n"16872026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)16882026/09/21 13:48:01 INFO Completed upload id=116892026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16902026/09/21 13:48:01 OK 20260905000000_add_claims.sql (3.81ms)16912026/09/21 13:48:01 INFO Received create pin request method=POST path=/api/pins/myapp16922026/09/21 13:48:01 INFO Completed upload id=316932026/09/21 13:48:01 INFO Upload complete. (245ms)16942026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (2.06ms)16952026/09/21 13:48:01 goose: successfully migrated database to version: 202609200000001696=== NAME TestClientSharedPathCommittedMidPush1697 client_integration_test.go:680: Retrieved narinfo from S3:1698 StorePath: /build/TestClientSharedPathCommittedMidPush3424766537/001/store/lpp67nx6g9a89l57s829xgin3xp3gmlb-shared-dep1699 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1700 Compression: zstd1701 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821702 NarSize: 1361703 References: 1704 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17052026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.95ms)17062026/09/21 13:48:01 OK 2_object_stats_trigger.sql (918.83µs)17072026/09/21 13:48:01 goose: up to current file version: 217082026/09/21 13:48:01 INFO All 1 paths already cached1709 client_integration_test.go:680: Retrieved narinfo from S3:1710 StorePath: /build/TestClientSharedPathCommittedMidPush3424766537/001/store/i7j0wwx2dd535hpg5a52smvzjafcqdy0-top1711 URL: nar/1anyg8f958a4yh2i4frna4b7j1cr00x8wcwn026w69k6p4y6yby2.nar.zst1712 Compression: zstd1713 NarHash: sha256:1anyg8f958a4yh2i4frna4b7j1cr00x8wcwn026w69k6p4y6yby21714 NarSize: 2241715 References: /build/TestClientSharedPathCommittedMidPush3424766537/001/store/lpp67nx6g9a89l57s829xgin3xp3gmlb-shared-dep1716 CA: text:sha256:0qcl843bcvycz5kj1d47w4rvmkvf5shvq7x4vr01azic6ghk4c9a1717=== NAME TestClientIntegration1718 client_integration_test.go:312: Retrieved narinfo from S3:1719 StorePath: /build/TestClientIntegration2370810505/002/store/z978yxibw07ryvjsbb8jgc6k9bqhvpyj-test-file.txt17202026-09-21 13:48:01.428 UTC [1172] ERROR: relation "goose_db_version" does not exist at character 3617212026-09-21 13:48:01.428 UTC [1172] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1722 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1723 Compression: zstd1724 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11725 NarSize: 1521726 References: 1727 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117282026/09/21 13:48:01 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2863902755/001/store/hb9g8ja3k5galp0h5rg25i6xrlwqzlih-pinned-file.txt narinfo_key=hb9g8ja3k5galp0h5rg25i6xrlwqzlih.narinfo17292026/09/21 13:48:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures17302026/09/21 13:48:01 INFO Garbage collection started1731 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1732 client_integration_test.go:313: Decompressed .ls content (64 bytes):1733 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1734 client_integration_test.go:316: Testing garbage collection...17352026/09/21 13:48:01 WARN readiness check failed error="closed pool"1736--- PASS: TestService_readinessHandler (1.50s)1737=== CONT TestService_AuthMiddleware_MTLSProxyHeader1738--- PASS: TestClientSharedPathCommittedMidPush (2.69s)1739=== CONT TestServerTLSConfig/no_client_CA1740=== CONT TestServerTLSConfig/not_a_PEM_file1741=== CONT TestServerTLSConfig/missing_CA_file1742--- PASS: TestServerTLSConfig (0.07s)1743 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1744 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1745 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1746=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17472026/09/21 13:48:01 INFO Received uploads request method=POST path=/1748=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17492026/09/21 13:48:01 INFO Received request for more parts method=POST path=/1750=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17512026/09/21 13:48:01 INFO Received complete multipart upload request method=POST path=/1752=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17532026/09/21 13:48:01 INFO Received uploads request method=POST path=/1754--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)1755 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1756 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1759=== CONT TestProxyWriteTimeout/narinfo1760=== CONT TestProxyWriteTimeout/unknown_size1761=== CONT TestProxyWriteTimeout/10_GiB_nar1762=== CONT TestProxyWriteTimeout/1_GiB_nar1763--- PASS: TestProxyWriteTimeout (0.06s)1764 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1765 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1766 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1767 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1768=== CONT TestIsValidUploadKey/narinfo1769=== CONT TestIsValidUploadKey/traversal_nar1770=== CONT TestIsValidUploadKey/traversal1771=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1772=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1773=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1774=== CONT TestIsValidUploadKey/index.html1775=== CONT TestIsValidUploadKey/absolute1776=== CONT TestIsValidUploadKey/nix-cache-info1777=== CONT TestIsValidUploadKey/realisation_plus_in_output1778=== CONT TestIsValidUploadKey/build_log1779=== CONT TestIsValidUploadKey/listing1780=== CONT TestIsValidUploadKey/nar_plain1781=== CONT TestIsValidUploadKey/nar_xz1782=== CONT TestIsValidUploadKey/build_log_home-manager_file1783=== CONT TestIsValidUploadKey/nar_zst1784=== CONT TestIsValidUploadKey/realisation1785=== CONT TestIsValidUploadKey/build_log_question_mark1786=== CONT TestIsValidUploadKey/build_log_plus_in_name1787=== CONT TestIsValidUploadKey/build_log_equals1788=== CONT TestIsValidUploadKey/unknown_type1789=== CONT TestIsValidUploadKey/empty_key1790--- PASS: TestIsValidUploadKey (0.06s)1791 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1792 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1793 --- PASS: TestIsValidUploadKey/traversal (0.00s)1794 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1796 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1797 --- PASS: TestIsValidUploadKey/index.html (0.00s)1798 --- PASS: TestIsValidUploadKey/absolute (0.00s)1799 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1800 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1801 --- PASS: TestIsValidUploadKey/build_log (0.00s)1802 --- PASS: TestIsValidUploadKey/listing (0.00s)1803 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1804 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1805 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1806 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1807 --- PASS: TestIsValidUploadKey/realisation (0.00s)1808 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1809 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1810 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1811 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1812 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1813=== CONT TestIsValidCachePath/narinfo1814=== CONT TestIsValidCachePath/index.html1815=== CONT TestIsValidCachePath/short_hash1816=== CONT TestIsValidCachePath/wrong_extension1817=== CONT TestIsValidCachePath/leading_slash1818=== CONT TestIsValidCachePath/empty1819=== CONT TestIsValidCachePath/random_path1820=== CONT TestIsValidCachePath/invalid_char_u1821=== CONT TestIsValidCachePath/invalid_char_e1822=== CONT TestIsValidCachePath/traversal_parent1823=== CONT TestIsValidCachePath/nar_uncompressed1824=== CONT TestIsValidCachePath/nix-cache-info1825=== CONT TestIsValidCachePath/traversal_in_middle1826=== CONT TestIsValidCachePath/realisation1827=== CONT TestIsValidCachePath/ls1828=== CONT TestIsValidCachePath/log1829=== CONT TestIsValidCachePath/nar_xz1830=== CONT TestIsValidCachePath/nar_zst1831=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1832=== CONT TestIsValidCachePath/nar_bz21833=== CONT TestClientErrorHandling/InvalidStorePath1834--- PASS: TestIsValidCachePath (0.00s)1835 --- PASS: TestIsValidCachePath/narinfo (0.00s)1836 --- PASS: TestIsValidCachePath/index.html (0.00s)1837 --- PASS: TestIsValidCachePath/short_hash (0.00s)1838 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1839 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1840 --- PASS: TestIsValidCachePath/empty (0.00s)1841 --- PASS: TestIsValidCachePath/random_path (0.00s)1842 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1843 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1844 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1845 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1846 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1847 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1848 --- PASS: TestIsValidCachePath/realisation (0.00s)1849 --- PASS: TestIsValidCachePath/ls (0.00s)1850 --- PASS: TestIsValidCachePath/log (0.00s)1851 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1852 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1853 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1854 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)18552026/09/21 13:48:01 INFO Aborted multipart uploads count=01856=== NAME TestNARDeduplicationMetadataUploadBug1857 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2921477191/001/store/kkm632yv0n4k871kr9bi459c43v5klhn-file1.txt18582026/09/21 13:48:01 WARN Force mode enabled - objects will be deleted immediately without grace period18592026/09/21 13:48:01 OK 20241026095416_initial_model.sql (12.15ms)18602026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)18612026/09/21 13:48:01 OK 20251218171726_add_pins.sql (4.72ms)18622026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)1863--- PASS: TestService_healthCheckHandler (1.43s)1864=== CONT TestClientErrorHandling/ServerNotAvailable18652026/09/21 13:48:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures18662026/09/21 13:48:01 INFO Garbage collection started18672026/09/21 13:48:01 OK 20260905000000_add_claims.sql (4.7ms)18682026-09-21 13:48:01.475 UTC [1213] ERROR: relation "goose_db_version" does not exist at character 3618692026-09-21 13:48:01.475 UTC [1213] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18702026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (3.59ms)18712026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000018722026/09/21 13:48:01 INFO Aborted multipart uploads count=018732026/09/21 13:48:01 OK 1_commit_pending_closure.sql (3.14ms)18742026/09/21 13:48:01 OK 2_object_stats_trigger.sql (2.94ms)18752026/09/21 13:48:01 goose: up to current file version: 218762026/09/21 13:48:01 WARN Force mode enabled - objects will be deleted immediately without grace period18772026/09/21 13:48:01 OK 20241026095416_initial_model.sql (15.79ms)18782026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)18792026/09/21 13:48:01 OK 20251218171726_add_pins.sql (3.92ms)1880--- PASS: TestReadProxyHead (1.40s)1881=== CONT TestClientErrorHandling/InvalidAuthToken18822026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)18832026/09/21 13:48:01 OK 20260905000000_add_claims.sql (2.99ms)18842026-09-21 13:48:01.513 UTC [1250] ERROR: relation "goose_db_version" does not exist at character 3618852026-09-21 13:48:01.513 UTC [1250] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18862026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (2.94ms)18872026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000018882026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.15ms)18892026/09/21 13:48:01 OK 2_object_stats_trigger.sql (1.13ms)18902026/09/21 13:48:01 goose: up to current file version: 218912026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18922026-09-21 13:48:01.520 UTC [1254] ERROR: relation "goose_db_version" does not exist at character 3618932026-09-21 13:48:01.520 UTC [1254] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18942026/09/21 13:48:01 OK 20241026095416_initial_model.sql (11.47ms)18952026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)18962026/09/21 13:48:01 OK 20241026095416_initial_model.sql (9.78ms)18972026/09/21 13:48:01 OK 20251218171726_add_pins.sql (4.03ms)18982026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)18992026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)19002026/09/21 13:48:01 OK 20251218171726_add_pins.sql (5.71ms)19012026/09/21 13:48:01 OK 20260905000000_add_claims.sql (4.39ms)19022026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (3.64ms)19032026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000019042026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)19052026/09/21 13:48:01 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/present19062026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.76ms)19072026/09/21 13:48:01 OK 20260905000000_add_claims.sql (3.71ms)19082026/09/21 13:48:01 OK 2_object_stats_trigger.sql (1.89ms)19092026/09/21 13:48:01 goose: up to current file version: 219102026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (2.9ms)19112026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000019122026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures19132026/09/21 13:48:01 OK 1_commit_pending_closure.sql (2.94ms)19142026/09/21 13:48:01 OK 2_object_stats_trigger.sql (1.8ms)19152026/09/21 13:48:01 goose: up to current file version: 219162026/09/21 13:48:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19172026/09/21 13:48:01 INFO Uploading kkm632yv0n4k871kr9bi459c43v5klhn-file1.txt (160B)19182026/09/21 13:48:01 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19192026-09-21 13:48:01.586 UTC [1307] ERROR: relation "goose_db_version" does not exist at character 3619202026-09-21 13:48:01.586 UTC [1307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19212026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19222026/09/21 13:48:01 WARN Failed to register uploaded object key=kkm632yv0n4k871kr9bi459c43v5klhn.ls error="server returned 404: 404 page not found\n"19232026/09/21 13:48:01 INFO Signed narinfos id=1 count=119242026/09/21 13:48:01 INFO Uploading 1 narinfos19252026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19262026/09/21 13:48:01 WARN Failed to register uploaded object key=kkm632yv0n4k871kr9bi459c43v5klhn.narinfo error="server returned 404: 404 page not found\n"19272026/09/21 13:48:01 INFO Completed upload id=119282026/09/21 13:48:01 INFO Upload complete. (124ms)19292026/09/21 13:48:01 OK 20241026095416_initial_model.sql (10.34ms)1930=== NAME TestNARDeduplicationMetadataUploadBug1931 metadata_upload_test.go:54: Retrieved narinfo from S3:1932 StorePath: /build/TestNARDeduplicationMetadataUploadBug2921477191/001/store/kkm632yv0n4k871kr9bi459c43v5klhn-file1.txt1933 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1934 Compression: zstd1935 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1936 NarSize: 1601937 References: 1938 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19392026/09/21 13:48:01 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)19402026/09/21 13:48:01 OK 20251218171726_add_pins.sql (3.18ms)1941 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1942 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1943 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19442026/09/21 13:48:01 OK 20260628120000_add_object_size_and_stats.sql (3.23ms)19452026/09/21 13:48:01 OK 20260905000000_add_claims.sql (3.51ms)19462026/09/21 13:48:01 OK 20260920000000_drop_claims.sql (1.97ms)19472026/09/21 13:48:01 goose: successfully migrated database to version: 2026092000000019482026/09/21 13:48:01 OK 1_commit_pending_closure.sql (1.96ms)19492026/09/21 13:48:01 OK 2_object_stats_trigger.sql (861.69µs)19502026/09/21 13:48:01 goose: up to current file version: 21951 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2921477191/001/store/3lw5npbbmpzx9jam99fyfg9ws39fgpsb-file2.txt19522026/09/21 13:48:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.418175ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19532026/09/21 13:48:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19542026/09/21 13:48:01 INFO Received uploads request method=POST path=/api/pending_closures19552026/09/21 13:48:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19562026/09/21 13:48:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19572026/09/21 13:48:01 INFO Signed narinfos id=2 count=119582026/09/21 13:48:01 WARN Failed to register uploaded object key=3lw5npbbmpzx9jam99fyfg9ws39fgpsb.ls error="server returned 404: 404 page not found\n"19592026/09/21 13:48:01 INFO Uploading 1 narinfos19602026/09/21 13:48:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19612026/09/21 13:48:01 WARN Failed to register uploaded object key=3lw5npbbmpzx9jam99fyfg9ws39fgpsb.narinfo error="server returned 404: 404 page not found\n"19622026/09/21 13:48:01 INFO Completed upload id=219632026/09/21 13:48:01 INFO Upload complete. (87ms)1964 metadata_upload_test.go:76: Retrieved narinfo from S3:1965 StorePath: /build/TestNARDeduplicationMetadataUploadBug2921477191/001/store/3lw5npbbmpzx9jam99fyfg9ws39fgpsb-file2.txt1966 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1967 Compression: zstd1968 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1969 NarSize: 1601970 References: 1971 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1972 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1973 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1974 {"version":1,"root":{"type":"regular","size":44}}1975--- PASS: TestNARDeduplicationMetadataUploadBug (1.88s)1976=== CONT TestParseSingleRange/none1977=== CONT TestParseSingleRange/start_far_past_EOF1978=== CONT TestParseSingleRange/start_past_EOF1979=== CONT TestParseSingleRange/single_byte1980=== CONT TestParseSingleRange/suffix_exceeds_size1981=== CONT TestParseSingleRange/suffix1982=== CONT TestParseSingleRange/end_clamped_to_size1983=== CONT TestParseSingleRange/open-ended1984=== CONT TestParseSingleRange/closed1985=== CONT TestParseSingleRange/multi-range_ignored1986=== CONT TestParseSingleRange/unknown_unit1987=== CONT TestParseSingleRange/malformed_end_before_start1988=== CONT TestParseSingleRange/malformed_no_dash1989=== CONT TestParseSingleRange/malformed_both_empty1990--- PASS: TestParseSingleRange (0.00s)1991 --- PASS: TestParseSingleRange/none (0.00s)1992 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1993 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1994 --- PASS: TestParseSingleRange/single_byte (0.00s)1995 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1996 --- PASS: TestParseSingleRange/suffix (0.00s)1997 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1998 --- PASS: TestParseSingleRange/open-ended (0.00s)1999 --- PASS: TestParseSingleRange/closed (0.00s)2000 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2001 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2002 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2003 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2004 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2005=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20062026/09/21 13:48:01 INFO Received request for more parts method=POST path=/20072026/09/21 13:48:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.23358ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2008=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20092026/09/21 13:48:01 INFO Received complete multipart upload request method=POST path=/2010=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20112026/09/21 13:48:01 INFO Received uploads request method=POST path=/2012--- PASS: TestReadProxyConditionalGet (1.95s)2013=== CONT TestResolveDBConnectionString/flag_wins2014=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2015=== CONT TestResolveDBConnectionString/missing_file_is_an_error2016=== CONT TestResolveDBConnectionString/nothing_configured2017=== CONT TestResolveDBConnectionString/file_when_flag_empty2018=== CONT TestCacheConfigHandler/full_config,_no_issuer2019--- PASS: TestResolveDBConnectionString (0.00s)2020 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2021 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2022 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2023 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2024 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2025=== CONT TestCacheConfigHandler/no_signing_keys2026=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2027=== CONT TestCacheConfigHandler/no_cache_url_configured2028--- PASS: TestCacheConfigHandler (0.00s)2029 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2030 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2031 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2032 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2033--- PASS: TestReadProxyInvalidPath (1.68s)2034--- PASS: TestReadRedirectKeepsNarinfoProxied (1.55s)2035--- PASS: TestReadProxy404 (1.50s)2036--- PASS: TestObjectStatsTrigger (1.54s)20372026/09/21 13:48:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=812.42185ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2038--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2039 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.11s)2040 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)2041 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.88s)20422026/09/21 13:48:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.697170458s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20432026/09/21 13:48:03 INFO Received uploads request method=POST path=/api/pending_closures2044=== RUN TestService_RequireScope_OIDC/builder_may_write2045=== PAUSE TestService_RequireScope_OIDC/builder_may_write2046=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2047=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2048=== RUN TestService_RequireScope_OIDC/ops_may_admin2049=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2050=== RUN TestService_RequireScope_OIDC/ops_may_not_write2051=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2052=== RUN TestService_RequireScope_OIDC/reader_may_not_write2053=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2054=== RUN TestService_RequireScope_OIDC/static_token_may_admin2055=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2056=== RUN TestService_RequireScope_OIDC/static_token_may_write2057=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2058=== RUN TestService_RequireScope_OIDC/reader_may_read2059=== PAUSE TestService_RequireScope_OIDC/reader_may_read2060=== RUN TestService_RequireScope_OIDC/writer_implies_read2061=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2062=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2063=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2064=== CONT TestService_RequireScope_OIDC/builder_may_write2065=== CONT TestService_RequireScope_OIDC/writer_implies_read2066=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2067=== CONT TestService_RequireScope_OIDC/ops_may_not_write2068=== CONT TestService_RequireScope_OIDC/static_token_may_admin2069=== CONT TestService_RequireScope_OIDC/reader_may_not_write2070=== CONT TestService_RequireScope_OIDC/reader_may_read2071=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2072=== CONT TestService_RequireScope_OIDC/ops_may_admin2073=== CONT TestService_RequireScope_OIDC/static_token_may_write2074--- PASS: TestService_RequireScope_OIDC (2.52s)2075 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2077 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2078 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2079 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2080 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2081 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2082 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2085--- PASS: TestService_ReadAuthMiddleware (2.45s)20862026/09/21 13:48:03 INFO Received cleanup request method=DELETE path=/api/pending_closures20872026/09/21 13:48:03 INFO Aborted multipart uploads count=12088--- PASS: TestMultipartCleanup (2.64s)20892026/09/21 13:48:03 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=02090--- PASS: TestService_ReadScope_PublicByDefault (2.20s)2091=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2092=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2093=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2094=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2095=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2096=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2097=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2098=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2099=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2100=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2101=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2102=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21032026/09/21 13:48:03 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]21042026/09/21 13:48:03 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=021052026/09/21 13:48:03 WARN Authentication failed token_preview=eyJhbGciOi...DfC8oETYUQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2106--- PASS: TestService_AuthMiddleware_OIDC (2.21s)2107 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2108 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2109 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2110 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2111=== NAME TestClientCADerivations2112 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2957875662/001/store/d4n9z580w4yyx7w1dwjja0mxqghqi2vs-ca-test2113--- PASS: TestCacheStatsHandler (2.20s)2114=== NAME TestClientCADerivations2115 client_ca_test.go:139: Found 1 dependencies (including self)21162026/09/21 13:48:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21172026/09/21 13:48:03 WARN mTLS auth: bound subjects configured but subject DN unavailable21182026/09/21 13:48:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2119--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.17s)21202026/09/21 13:48:03 INFO Aborted multipart uploads count=021212026/09/21 13:48:03 WARN Force mode enabled - objects will be deleted immediately without grace period21222026/09/21 13:48:03 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=021232026/09/21 13:48:03 INFO Vacuumed table table=pending_closures21242026/09/21 13:48:03 INFO Vacuumed table table=pending_objects21252026/09/21 13:48:03 INFO Vacuumed table table=multipart_uploads21262026/09/21 13:48:03 INFO Vacuumed table table=closures21272026/09/21 13:48:03 INFO Vacuumed table table=objects2128--- PASS: TestGCMetrics (2.17s)2129--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.15s)21302026/09/21 13:48:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21312026/09/21 13:48:03 INFO Received uploads request method=POST path=/api/pending_closures21322026/09/21 13:48:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21332026/09/21 13:48:03 INFO Uploading d4n9z580w4yyx7w1dwjja0mxqghqi2vs-ca-test (144B)21342026/09/21 13:48:03 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21352026/09/21 13:48:03 WARN Failed to register uploaded object key=log/7vfri7z9wpagvcaq5fy6xhavf4cy2i46-ca-test.drv error="server returned 404: 404 page not found\n"21362026/09/21 13:48:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21372026/09/21 13:48:03 WARN Failed to register uploaded object key=d4n9z580w4yyx7w1dwjja0mxqghqi2vs.ls error="server returned 404: 404 page not found\n"21382026/09/21 13:48:03 INFO Signed narinfos id=1 count=121392026/09/21 13:48:03 INFO Uploading 1 narinfos21402026/09/21 13:48:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21412026/09/21 13:48:03 WARN Failed to register uploaded object key=d4n9z580w4yyx7w1dwjja0mxqghqi2vs.narinfo error="server returned 404: 404 page not found\n"21422026/09/21 13:48:03 INFO Completed upload id=121432026/09/21 13:48:03 INFO Upload complete. (100ms)2144=== NAME TestClientCADerivations2145 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2957875662/001/store/d4n9z580w4yyx7w1dwjja0mxqghqi2vs-ca-test2146 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2147 Compression: zstd2148 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2149 NarSize: 1442150 References: 2151 Deriver: /build/TestClientCADerivations2957875662/001/store/7vfri7z9wpagvcaq5fy6xhavf4cy2i46-ca-test.drv2152 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2153 client_ca_test.go:185: Checking for realisation files in S3...2154 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2155 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2156=== NAME TestOrphanedObjectsGC2157 orphaned_objects_gc_test.go:290: GC Test Summary:2158 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2159 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2160 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2161 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2162 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2163--- PASS: TestOrphanedObjectsGC (2.87s)21642026/09/21 13:48:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2165=== NAME TestClientCADerivations2166 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2167 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2168 error: binary cache 's3://bucket47?endpoint=http://localhost:45815®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2957875662/001/store'2169 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12170--- PASS: TestClientCADerivations (2.85s)21712026/09/21 13:48:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21722026/09/21 13:48:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21732026/09/21 13:48:04 WARN Rate limiter enabled after throttle name=s3-test rate=521742026/09/21 13:48:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2175=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2176 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102177 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002178--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.58s)2179=== NAME TestOrphanedObjectsGCStressTest2180 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2181 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21822026/09/21 13:48:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21832026/09/21 13:48:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.934419ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21842026/09/21 13:48:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.710628ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/09/21 13:48:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=869.386647ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2186 orphaned_objects_gc_test.go:509: Stress test completed successfully:2187 orphaned_objects_gc_test.go:510: - Active objects preserved: 202188 orphaned_objects_gc_test.go:511: - Objects deleted: 2102189 orphaned_objects_gc_test.go:512: - Total GC'd: 2102190--- PASS: TestOrphanedObjectsGCStressTest (5.40s)21912026/09/21 13:48:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.649444936s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21922026/09/21 13:48:07 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=021932026/09/21 13:48:07 INFO Vacuumed table table=pending_closures21942026/09/21 13:48:07 INFO Vacuumed table table=pending_objects21952026/09/21 13:48:07 INFO Vacuumed table table=multipart_uploads21962026/09/21 13:48:07 INFO Vacuumed table table=closures21972026/09/21 13:48:07 INFO Vacuumed table table=objects21982026/09/21 13:48:07 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=021992026/09/21 13:48:07 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02200=== NAME TestClientIntegration2201 client_integration_test.go:323: Objects in database after GC:2202 client_integration_test.go:323: Successfully deleted all objects with GC --force2203--- PASS: TestClientIntegration (8.58s)22042026/09/21 13:48:07 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=022052026/09/21 13:48:07 INFO Vacuumed table table=pending_closures22062026/09/21 13:48:07 INFO Vacuumed table table=pending_objects22072026/09/21 13:48:07 INFO Vacuumed table table=multipart_uploads22082026/09/21 13:48:07 INFO Vacuumed table table=closures22092026/09/21 13:48:07 INFO Vacuumed table table=objects22102026/09/21 13:48:08 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"22112026/09/21 13:48:08 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_closures22122026/09/21 13:48:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.508753ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22132026/09/21 13:48:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.929249ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22142026/09/21 13:48:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=816.587414ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22152026/09/21 13:48:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02216=== NAME TestPinProtectsFromGC2217 client_integration_test.go:794: Pin successfully protected closure from garbage collection2218--- PASS: TestPinProtectsFromGC (10.83s)22192026/09/21 13:48:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.55334405s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2220--- PASS: TestClientErrorHandling (0.00s)2221 --- PASS: TestClientErrorHandling/InvalidStorePath (2.21s)2222 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.30s)2223 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.75s)2224PASS22252026-09-21 13:48:11.458 UTC [128] LOG: received smart shutdown request22262026-09-21 13:48:11.462 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 122272026-09-21 13:48:11.472 UTC [133] LOG: shutting down22282026-09-21 13:48:11.473 UTC [133] LOG: checkpoint starting: shutdown immediate22292026-09-21 13:48:12.288 UTC [133] LOG: checkpoint complete: wrote 11415 buffers (69.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.237 s, sync=0.561 s, total=0.816 s; sync files=18738, longest=0.106 s, average=0.001 s; distance=255742 kB, estimate=255742 kB; lsn=0/111256F0, redo lsn=0/111256F022302026-09-21 13:48:12.422 UTC [128] LOG: database system is shut down2231Running OIDC tests...2232=== RUN TestGlobMatch2233=== PAUSE TestGlobMatch2234=== RUN TestAudienceForIssuer2235=== PAUSE TestAudienceForIssuer2236=== RUN TestValidateToken_ValidToken2237=== PAUSE TestValidateToken_ValidToken2238=== RUN TestValidateToken_WrongAudience2239=== PAUSE TestValidateToken_WrongAudience2240=== RUN TestValidateToken_Expired2241=== PAUSE TestValidateToken_Expired2242=== RUN TestValidateToken_BoundClaimsMismatch2243=== PAUSE TestValidateToken_BoundClaimsMismatch2244=== RUN TestValidateToken_BoundSubjectMismatch2245=== PAUSE TestValidateToken_BoundSubjectMismatch2246=== RUN TestValidateToken_MultipleProviders2247=== PAUSE TestValidateToken_MultipleProviders2248=== RUN TestValidateToken_NoMatchingProvider2249=== PAUSE TestValidateToken_NoMatchingProvider2250=== RUN TestValidateToken_KubernetesServiceAccount2251=== PAUSE TestValidateToken_KubernetesServiceAccount2252=== RUN TestNewValidator_KubernetesRequiresCA2253=== PAUSE TestNewValidator_KubernetesRequiresCA2254=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2255=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2256=== RUN TestScopes_LegacyProviderDefaultsToWrite2257=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2258=== RUN TestScopes_Rules2259=== PAUSE TestScopes_Rules2260=== RUN TestScopes_ConfigValidation2261=== PAUSE TestScopes_ConfigValidation2262=== CONT TestGlobMatch2263=== CONT TestScopes_LegacyProviderDefaultsToWrite2264=== CONT TestNewValidator_KubernetesRequiresCA2265=== RUN TestGlobMatch/foo_foo2266=== PAUSE TestGlobMatch/foo_foo2267=== RUN TestGlobMatch/foo_bar2268=== PAUSE TestGlobMatch/foo_bar2269=== RUN TestGlobMatch/*_2270=== PAUSE TestGlobMatch/*_2271=== CONT TestValidateToken_MultipleProviders2272=== CONT TestValidateToken_BoundSubjectMismatch2273=== CONT TestValidateToken_BoundClaimsMismatch2274=== CONT TestValidateToken_Expired2275=== CONT TestValidateToken_WrongAudience2276=== CONT TestValidateToken_ValidToken2277=== CONT TestAudienceForIssuer2278--- PASS: TestAudienceForIssuer (0.00s)2279=== CONT TestValidateToken_KubernetesServiceAccount2280=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2281=== CONT TestScopes_ConfigValidation2282=== CONT TestScopes_Rules2283=== CONT TestValidateToken_NoMatchingProvider2284=== RUN TestGlobMatch/*_anything2285=== PAUSE TestGlobMatch/*_anything2286=== RUN TestGlobMatch/foo*_foo2287=== PAUSE TestGlobMatch/foo*_foo2288=== RUN TestGlobMatch/foo*_foobar2289=== PAUSE TestGlobMatch/foo*_foobar2290=== RUN TestGlobMatch/foo*_bar2291=== PAUSE TestGlobMatch/foo*_bar2292=== RUN TestGlobMatch/*bar_bar2293=== PAUSE TestGlobMatch/*bar_bar2294=== RUN TestGlobMatch/*bar_foobar2295=== PAUSE TestGlobMatch/*bar_foobar2296=== RUN TestGlobMatch/*bar_foo2297=== PAUSE TestGlobMatch/*bar_foo2298=== RUN TestGlobMatch/foo*bar_foobar2299=== PAUSE TestGlobMatch/foo*bar_foobar2300=== RUN TestGlobMatch/foo*bar_foo123bar2301=== PAUSE TestGlobMatch/foo*bar_foo123bar2302=== RUN TestGlobMatch/foo*bar_foobarbaz2303=== PAUSE TestGlobMatch/foo*bar_foobarbaz2304=== RUN TestGlobMatch/*/*_foo/bar2305=== PAUSE TestGlobMatch/*/*_foo/bar2306=== RUN TestGlobMatch/*/*_foo2307=== PAUSE TestGlobMatch/*/*_foo2308=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2309=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2310=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02311=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02312=== RUN TestGlobMatch/refs/*/main_refs/heads/main2313=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2314=== RUN TestGlobMatch/fo?_foo2315=== PAUSE TestGlobMatch/fo?_foo2316=== RUN TestGlobMatch/fo?_fo2317=== PAUSE TestGlobMatch/fo?_fo2318=== RUN TestGlobMatch/fo?_fooo2319=== PAUSE TestGlobMatch/fo?_fooo2320=== RUN TestGlobMatch/?oo_foo2321=== PAUSE TestGlobMatch/?oo_foo2322=== RUN TestGlobMatch/?oo_boo2323=== PAUSE TestGlobMatch/?oo_boo2324=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2325=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2326=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2327=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2328=== CONT TestGlobMatch/foo_foo2329=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2330=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2331=== CONT TestGlobMatch/?oo_boo2332=== CONT TestGlobMatch/?oo_foo2333=== CONT TestGlobMatch/foo*bar_foo123bar2334=== CONT TestGlobMatch/foo*bar_foobar2335=== CONT TestGlobMatch/fo?_fooo2336=== CONT TestGlobMatch/fo?_fo2337=== CONT TestGlobMatch/fo?_foo2338=== CONT TestGlobMatch/*bar_foo2339=== CONT TestGlobMatch/refs/*/main_refs/heads/main2340=== CONT TestGlobMatch/*bar_foobar2341=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2342=== CONT TestGlobMatch/foo*bar_foobarbaz2343--- PASS: TestScopes_ConfigValidation (0.00s)2344=== CONT TestGlobMatch/foo*_bar23452026/09/21 13:48:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37653/oidc2346=== CONT TestGlobMatch/foo*_foobar2347=== CONT TestGlobMatch/foo*_foo2348=== CONT TestGlobMatch/*_anything23492026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43319/oidc2350=== CONT TestGlobMatch/*_2351=== CONT TestGlobMatch/foo_bar23522026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44975/oidc2353=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.023542026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42343/oidc2355=== CONT TestGlobMatch/*/*_foo2356=== CONT TestGlobMatch/*/*_foo/bar2357=== CONT TestGlobMatch/*bar_bar23582026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36705/oidc2359--- PASS: TestGlobMatch (0.01s)2360 --- PASS: TestGlobMatch/foo_foo (0.00s)2361 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2362 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2363 --- PASS: TestGlobMatch/?oo_boo (0.00s)2364 --- PASS: TestGlobMatch/?oo_foo (0.00s)2365 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2366 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2367 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2368 --- PASS: TestGlobMatch/fo?_fo (0.00s)2369 --- PASS: TestGlobMatch/fo?_foo (0.00s)2370 --- PASS: TestGlobMatch/*bar_foo (0.00s)2371 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2372 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2373 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2374 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2375 --- PASS: TestGlobMatch/foo*_bar (0.00s)2376 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2377 --- PASS: TestGlobMatch/foo*_foo (0.00s)2378 --- PASS: TestGlobMatch/*_anything (0.00s)2379 --- PASS: TestGlobMatch/*_ (0.00s)2380 --- PASS: TestGlobMatch/foo_bar (0.00s)2381 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2382 --- PASS: TestGlobMatch/*/*_foo (0.00s)2383 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2384 --- PASS: TestGlobMatch/*bar_bar (0.00s)23852026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45389/oidc23862026/09/21 13:48:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33513/oidc23872026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45305/oidc23882026/09/21 13:48:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41897/oidc23892026/09/21 13:48:13 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45203/oidc23902026/09/21 13:48:13 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232391--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2392--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2393--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2394--- PASS: TestValidateToken_WrongAudience (0.01s)2395--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)23962026/09/21 13:48:13 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:424912397--- PASS: TestValidateToken_Expired (0.01s)2398--- PASS: TestValidateToken_ValidToken (0.01s)2399--- PASS: TestValidateToken_MultipleProviders (0.02s)2400--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)24012026/09/21 13:48:13 http: TLS handshake error from 127.0.0.1:49532: remote error: tls: bad certificate2402--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2403--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2404--- PASS: TestScopes_Rules (0.02s)2405PASS2406Running hook tests...2407=== RUN TestSendPathsEmpty2408=== PAUSE TestSendPathsEmpty2409=== RUN TestQueueEnqueueAndFetch2410=== PAUSE TestQueueEnqueueAndFetch2411=== RUN TestQueueDeduplication2412=== PAUSE TestQueueDeduplication2413=== RUN TestQueueRemove2414=== PAUSE TestQueueRemove2415=== RUN TestQueueFetchBatchLimit2416=== PAUSE TestQueueFetchBatchLimit2417=== RUN TestQueueRetryMovesToBack2418=== PAUSE TestQueueRetryMovesToBack2419=== RUN TestQueueFetchRemoveLifecycle2420=== PAUSE TestQueueFetchRemoveLifecycle2421=== RUN TestQueueConcurrentWriters2422=== PAUSE TestQueueConcurrentWriters2423=== RUN TestQueueRemoveLargeClosure2424=== PAUSE TestQueueRemoveLargeClosure2425=== RUN TestServerClientIntegration2426=== PAUSE TestServerClientIntegration2427=== RUN TestServerQueueError2428=== PAUSE TestServerQueueError2429=== RUN TestGetListenerSocketActivation2430 server_test.go:210: === RUN TestGetListenerSocketActivation2431 --- PASS: TestGetListenerSocketActivation (0.00s)2432 PASS2433 2434--- PASS: TestGetListenerSocketActivation (0.01s)2435=== RUN TestDrainIsolatesPoisonPath2436=== PAUSE TestDrainIsolatesPoisonPath2437=== RUN TestRunNotBlockedByPoisonHead2438=== PAUSE TestRunNotBlockedByPoisonHead2439=== RUN TestDrainGivesUpWhenServerDown2440=== PAUSE TestDrainGivesUpWhenServerDown2441=== RUN TestFailedPathPrunedByLaterClosure2442=== PAUSE TestFailedPathPrunedByLaterClosure2443=== RUN TestWorkerUploadsAndRemoves2444=== PAUSE TestWorkerUploadsAndRemoves2445=== RUN TestWorkerSkipsGCdPaths2446=== PAUSE TestWorkerSkipsGCdPaths2447=== RUN TestWorkerPrunesClosureDeps2448=== PAUSE TestWorkerPrunesClosureDeps2449=== RUN TestDrainTimeout2450=== PAUSE TestDrainTimeout2451=== CONT TestSendPathsEmpty2452=== CONT TestServerQueueError2453=== CONT TestQueueRemoveLargeClosure2454--- PASS: TestSendPathsEmpty (0.00s)2455=== CONT TestQueueFetchBatchLimit2456=== CONT TestQueueRemove2457=== CONT TestQueueDeduplication2458=== CONT TestQueueEnqueueAndFetch2459=== CONT TestWorkerUploadsAndRemoves2460=== CONT TestDrainTimeout24612026/09/21 13:48:13 ERROR Failed to queue paths error="permission denied" count=12462=== CONT TestWorkerPrunesClosureDeps2463=== CONT TestWorkerSkipsGCdPaths2464=== CONT TestDrainGivesUpWhenServerDown2465=== CONT TestFailedPathPrunedByLaterClosure2466=== CONT TestQueueConcurrentWriters2467=== CONT TestQueueFetchRemoveLifecycle2468=== CONT TestRunNotBlockedByPoisonHead2469=== CONT TestDrainIsolatesPoisonPath2470=== CONT TestServerClientIntegration2471=== CONT TestQueueRetryMovesToBack2472--- PASS: TestServerQueueError (0.00s)2473--- PASS: TestServerClientIntegration (0.00s)24742026/09/21 13:48:13 INFO Upload queue status pending=224752026/09/21 13:48:13 INFO Uploading batch count=424762026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=424772026/09/21 13:48:13 INFO Uploading batch count=224782026/09/21 13:48:13 INFO Uploading batch count=124792026/09/21 13:48:13 INFO Upload queue status pending=224802026/09/21 13:48:13 INFO Uploading batch count=224812026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=224822026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2981360632/002/a24832026/09/21 13:48:13 INFO Upload queue status pending=324842026/09/21 13:48:13 INFO Uploading batch count=22485--- PASS: TestQueueFetchBatchLimit (0.02s)24862026/09/21 13:48:13 INFO Uploading batch count=124872026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=124882026/09/21 13:48:13 INFO Upload queue status pending=224892026/09/21 13:48:13 INFO Uploading batch count=12490--- PASS: TestQueueEnqueueAndFetch (0.01s)24912026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2981360632/002/b24922026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=124932026/09/21 13:48:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1602824911/002/nonexistent24942026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1697644642/002/bbb2495--- PASS: TestQueueRemove (0.02s)2496--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24972026/09/21 13:48:13 INFO Uploading batch count=124982026/09/21 13:48:13 INFO Uploading batch count=124992026/09/21 13:48:13 INFO Uploading batch count=225002026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=225012026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2981360632/002/c2502--- PASS: TestQueueDeduplication (0.02s)25032026/09/21 13:48:13 INFO Uploading batch count=125042026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2981360632/002/d2505--- PASS: TestQueueRetryMovesToBack (0.02s)25062026/09/21 13:48:13 INFO Uploading batch count=125072026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=125082026/09/21 13:48:13 INFO Uploading batch count=225092026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=225102026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2981360632/002/e25112026/09/21 13:48:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2981360632/002/f25122026/09/21 13:48:13 INFO Uploading batch count=125132026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=125142026/09/21 13:48:13 ERROR Drain finished with paths left in queue remaining=102515--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25162026/09/21 13:48:13 INFO Uploading batch count=125172026/09/21 13:48:13 ERROR Upload failed error="upload failed" count=125182026/09/21 13:48:13 ERROR Drain finished with paths left in queue remaining=12519--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2520--- PASS: TestDrainIsolatesPoisonPath (0.02s)2521--- PASS: TestWorkerPrunesClosureDeps (0.03s)2522--- PASS: TestWorkerUploadsAndRemoves (0.04s)2523--- PASS: TestWorkerSkipsGCdPaths (0.04s)2524--- PASS: TestQueueRemoveLargeClosure (0.16s)2525--- PASS: TestQueueConcurrentWriters (0.20s)25262026/09/21 13:48:13 ERROR Upload failed error="context deadline exceeded" count=225272026/09/21 13:48:13 ERROR Drain finished with paths left in queue remaining=42528--- PASS: TestDrainTimeout (0.21s)25292026/09/21 13:48:14 INFO Uploading batch count=125302026/09/21 13:48:14 INFO Uploading batch count=125312026/09/21 13:48:14 INFO Uploading batch count=125322026/09/21 13:48:14 ERROR Upload failed error="upload failed" count=125332026/09/21 13:48:14 INFO Uploading batch count=125342026/09/21 13:48:14 ERROR Upload failed error="upload failed" count=125352026/09/21 13:48:14 INFO Uploading batch count=125362026/09/21 13:48:14 ERROR Upload failed error="upload failed" count=125372026/09/21 13:48:14 INFO Uploading batch count=125382026/09/21 13:48:14 ERROR Upload failed error="upload failed" count=125392026/09/21 13:48:14 ERROR Drain finished with paths left in queue remaining=12540--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2541PASS