niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #240
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)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 TestStreamPushBatchesUnderLoad93=== CONT TestGetStorePathHash94=== RUN TestGetStorePathHash/valid_store_path95=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess96=== CONT TestRateLimiterFeedback97=== RUN TestRateLimiterFeedback/429_enables_limiter98=== PAUSE TestRateLimiterFeedback/429_enables_limiter99=== RUN TestRateLimiterFeedback/503_enables_limiter100=== PAUSE TestRateLimiterFeedback/503_enables_limiter101=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter102=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter103=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter104=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter105=== CONT TestStreamPushRequestLine106=== CONT TestPathInfoCACompatibility107=== RUN TestPathInfoCACompatibility/null_ca_field108=== PAUSE TestPathInfoCACompatibility/null_ca_field109=== CONT TestDoWithRetry_BodyReplayedViaGetBody110=== CONT TestParsePathInfoJSONMultiplePaths111=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths112=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths113=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths114=== CONT TestParsePathInfoJSON1152026/09/21 18:17:10 WARN Rate limiter enabled after throttle name=server-test rate=5116=== CONT TestResolveStorePath117=== CONT TestPathInfoHashCompatibility118=== CONT TestFileTokenMissing119=== CONT TestScriptTokenEmptyCommand120=== CONT TestScriptTokenScriptFails121=== CONT TestStreamPushReportsEveryPath122=== CONT TestScriptTokenBadJSON123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestShellSplitErrors127=== CONT TestSetClientTLSDoesNotMutateDefaultTransport128=== CONT TestFileTokenEmpty129=== CONT TestFileTokenReadsAndCaches130=== CONT TestStaticToken131=== PAUSE TestGetStorePathHash/valid_store_path132=== RUN TestPathInfoCACompatibility/old_string_format_-_text133=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text134=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive135=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths136=== RUN TestParsePathInfoJSON/Nix_format137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive139=== RUN TestPathInfoCACompatibility/new_structured_format_-_text140=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text141=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method142=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method143=== CONT TestStreamPushGivesUpOnDeadServer144--- PASS: TestShellSplitErrors (0.00s)145--- PASS: TestStaticToken (0.00s)146=== CONT TestDumpPathMatchesNix1472026/09/21 18:17:10 ERROR Upload failed error="connection refused" count=201482026/09/21 18:17:10 ERROR Server seems unavailable, giving up on batch untried=17149=== CONT TestSetClientTLSErrors150--- PASS: TestScriptTokenEmptyCommand (0.00s)151=== CONT TestStreamPushIsolatesFailures152=== RUN TestGetStorePathHash/basename_without_hyphen_should_error153=== CONT TestSetClientTLS154=== CONT TestEncodeNixBase32155=== RUN TestEncodeNixBase32/test_string_hash156--- PASS: TestStreamPushReportsEveryPath (0.00s)157--- PASS: TestResolveStorePath (0.00s)158=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error159=== CONT TestDumpPathWriterError160=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error161=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error162=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error163=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error164=== CONT TestConvertHashToNix32165=== RUN TestConvertHashToNix32/SRI_format_to_Nix32166--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)167--- PASS: TestScriptTokenScriptFails (0.00s)168=== CONT TestEncodeNixBase32WithRealHash169=== CONT TestUploadMultipart_PartsInParallel170=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== CONT TestCaseHackSuffix172--- PASS: TestFileTokenReadsAndCaches (0.00s)173=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1742026/09/21 18:17:10 ERROR Upload failed error=boom count=1175=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1772026/09/21 18:17:10 ERROR Upload failed error="bad path" count=3178=== CONT TestUploadMultipart_SupersededByPeer179=== RUN TestUploadMultipart_SupersededByPeer/exists180=== PAUSE TestEncodeNixBase32/test_string_hash181=== PAUSE TestParsePathInfoJSON/Nix_format182--- PASS: TestEncodeNixBase32WithRealHash (0.00s)183--- PASS: TestScriptTokenEmptyToken (0.00s)184--- PASS: TestFileTokenMissing (0.00s)185=== CONT TestFilterOversizedClosures186=== RUN TestFilterOversizedClosures/no_limit_keeps_everything187=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI188--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)189=== RUN TestSetClientTLS/rejects_connection_without_client_cert190=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI191=== CONT TestDumpPathSingleFile192=== PAUSE TestUploadMultipart_SupersededByPeer/exists193=== RUN TestUploadMultipart_SupersededByPeer/missing194=== PAUSE TestUploadMultipart_SupersededByPeer/missing195=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512196=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== CONT TestRegisterUploadedObjectReusesConnections198=== RUN TestConvertHashToNix32/already_Nix32_format199--- PASS: TestFileTokenEmpty (0.03s)200=== PAUSE TestConvertHashToNix32/already_Nix32_format201=== RUN TestConvertHashToNix32/invalid_format202=== PAUSE TestConvertHashToNix32/invalid_format203=== CONT TestShellSplit204--- PASS: TestShellSplit (0.00s)205=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter206=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter207--- PASS: TestDoServerRequestAttachesToken (0.04s)208=== CONT TestRateLimiterFeedback/503_enables_limiter209=== RUN TestSetClientTLSErrors/missing_cert_file210=== PAUSE TestSetClientTLSErrors/missing_cert_file211=== RUN TestSetClientTLSErrors/missing_key_file212=== PAUSE TestSetClientTLSErrors/missing_key_file213=== RUN TestSetClientTLSErrors/missing_ca_file214=== PAUSE TestSetClientTLSErrors/missing_ca_file215=== RUN TestSetClientTLSErrors/invalid_ca_file216=== PAUSE TestSetClientTLSErrors/invalid_ca_file217=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths218=== CONT TestRateLimiterFeedback/429_enables_limiter219=== CONT TestPathInfoCACompatibility/null_ca_field220=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method221=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive222=== CONT TestPathInfoCACompatibility/old_string_format_-_text223=== CONT TestGetStorePathHash/valid_store_path224=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error225=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error226=== CONT TestGetStorePathHash/basename_without_hyphen_should_error227=== CONT TestUploadMultipart_SupersededByPeer/exists228=== CONT TestUploadMultipart_SupersededByPeer/missing229=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)230=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512231--- PASS: TestStreamPushIsolatesFailures (0.03s)232=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths233--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)234 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)235 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)236=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon2372026/09/21 18:17:10 WARN Rate limiter enabled after throttle name=server-test rate=5238--- PASS: TestGetStorePathHash (0.01s)239 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)240 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)241 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)242 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)2432026/09/21 18:17:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34049244--- PASS: TestScriptTokenBadJSON (0.04s)245=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI246=== CONT TestConvertHashToNix32/invalid_format247=== CONT TestConvertHashToNix32/already_Nix32_format248=== CONT TestSetClientTLSErrors/missing_cert_file2492026/09/21 18:17:10 WARN Rate limiter enabled after throttle name=server-test rate=52502026/09/21 18:17:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:42427251=== CONT TestConvertHashToNix32/SRI_format_to_Nix32252--- PASS: TestPathInfoHashCompatibility (0.04s)253 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)254 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)255 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)256 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)257=== CONT TestSetClientTLSErrors/missing_ca_file2582026/09/21 18:17:10 WARN Rate limiter backed off name=server-test rate=52592026/09/21 18:17:10 WARN Rate limiter backed off name=server-test rate=5260=== CONT TestSetClientTLSErrors/missing_key_file261=== CONT TestSetClientTLSErrors/invalid_ca_file262=== CONT TestPathInfoCACompatibility/new_structured_format_-_text263=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything264=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2662026/09/21 18:17:10 WARN Rate limiter enabled after throttle name=server-test rate=5267=== RUN TestFilterOversizedClosures/all_closures_skipped2682026/09/21 18:17:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46747269=== PAUSE TestFilterOversizedClosures/all_closures_skipped270--- PASS: TestConvertHashToNix32 (0.03s)271 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)272 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)273 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)274=== RUN TestEncodeNixBase32/empty_input275=== PAUSE TestEncodeNixBase32/empty_input2762026/09/21 18:17:10 WARN Rate limiter backed off name=server-test rate=5277=== CONT TestEncodeNixBase32/test_string_hash2782026/09/21 18:17:10 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46747279=== RUN TestParsePathInfoJSON/Lix_format280=== PAUSE TestParsePathInfoJSON/Lix_format281=== RUN TestParsePathInfoJSON/empty_input282=== PAUSE TestParsePathInfoJSON/empty_input283=== RUN TestParsePathInfoJSON/whitespace_only284=== PAUSE TestParsePathInfoJSON/whitespace_only285=== CONT TestFilterOversizedClosures/no_limit_keeps_everything286=== CONT TestFilterOversizedClosures/all_closures_skipped2872026/09/21 18:17:10 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=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2892026/09/21 18:17:10 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=2000290=== CONT TestPartSizeForNAR291=== RUN TestPartSizeForNAR/zero_stays_at_minimum292=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert293=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA294=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA295=== RUN TestSetClientTLS/preserves_debug_logging_transport296=== PAUSE TestSetClientTLS/preserves_debug_logging_transport297--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)298 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)299 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)300=== CONT TestEncodeNixBase32/empty_input301=== RUN TestParsePathInfoJSON/invalid_JSON302=== PAUSE TestParsePathInfoJSON/invalid_JSON303=== CONT TestParsePathInfoJSON/Nix_format304=== CONT TestParsePathInfoJSON/whitespace_only305=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum306=== CONT TestSetClientTLS/rejects_connection_without_client_cert307=== RUN TestPartSizeForNAR/small_stays_at_minimum308=== PAUSE TestPartSizeForNAR/small_stays_at_minimum309=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum310=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum311=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts312=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts313=== RUN TestPartSizeForNAR/1_TiB314=== PAUSE TestPartSizeForNAR/1_TiB315=== CONT TestSetClientTLS/preserves_debug_logging_transport316=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA317--- PASS: TestRateLimiterFeedback (0.00s)318 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)319 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)320 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)321 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)322--- PASS: TestPathInfoCACompatibility (0.00s)323 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)324 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)325 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)326 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)327 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)328=== CONT TestParsePathInfoJSON/empty_input329=== CONT TestParsePathInfoJSON/Lix_format330=== CONT TestParsePathInfoJSON/invalid_JSON331=== RUN TestPartSizeForNAR/5_TiB_S3_max_object332=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object333=== RUN TestPartSizeForNAR/capped_at_5_GiB334=== PAUSE TestPartSizeForNAR/capped_at_5_GiB335=== CONT TestPartSizeForNAR/zero_stays_at_minimum336--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)337=== CONT TestPartSizeForNAR/capped_at_5_GiB338=== CONT TestPartSizeForNAR/5_TiB_S3_max_object339=== CONT TestPartSizeForNAR/1_TiB340=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts341=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum342=== CONT TestPartSizeForNAR/small_stays_at_minimum343--- PASS: TestFilterOversizedClosures (0.03s)344 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)345 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)346 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)347--- PASS: TestEncodeNixBase32 (0.04s)348 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)349 --- PASS: TestEncodeNixBase32/empty_input (0.00s)350--- PASS: TestPartSizeForNAR (0.00s)351 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)353 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)354 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)355 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)356 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)357 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)358--- PASS: TestParsePathInfoJSON (0.04s)359 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)361 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)362 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)363 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)364--- PASS: TestSetClientTLSErrors (0.03s)365 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)367 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)368 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)369--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)370--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3712026/09/21 18:17:10 http: TLS handshake error from 127.0.0.1:34260: remote error: tls: bad certificate372--- PASS: TestSetClientTLS (0.04s)373 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)374 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)375 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)376--- PASS: TestStreamPushRequestLine (0.06s)377--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)378--- PASS: TestCaseHackSuffix (0.07s)379--- PASS: TestDumpPathSingleFile (0.04s)380--- PASS: TestDumpPathWriterError (0.08s)381--- PASS: TestStreamPushBatchesUnderLoad (0.10s)382--- PASS: TestDumpPathMatchesNix (0.12s)383--- PASS: TestUploadMultipart_PartsInParallel (0.65s)384--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)385PASS386Running server tests...387The files belonging to this database system will be owned by user "nixbld".388This user must also own the server process.389390The database cluster will be initialized with locale "C".391The default database encoding has accordingly been set to "SQL_ASCII".392The default text search configuration will be set to "english".393394Data page checksums are enabled.395396creating directory /build/postgres566441692/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/postgres566441692/data -l logfile start413414/build/postgres566441692:5432 - no response4152026-09-21 18:17:11.875 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4162026-09-21 18:17:11.875 UTC [129] LOG: listening on Unix socket "/build/postgres566441692/.s.PGSQL.5432"4172026-09-21 18:17:11.880 UTC [136] LOG: database system was shut down at 2026-09-21 18:17:11 UTC4182026-09-21 18:17:11.884 UTC [129] LOG: database system is ready to accept connections419/build/postgres566441692:5432 - accepting connections420{"timestamp":"2026-09-21T18:17:12.181833987Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1487fc45-83c0-4a03-9807-7e180c6e7c6d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":430,"threadName":"rustfs-worker","threadId":"ThreadId(387)"}421=== RUN TestService_AuthMiddleware422=== PAUSE TestService_AuthMiddleware423=== RUN TestService_AuthMiddleware_MTLSProxyHeader424=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader425=== RUN TestService_AuthMiddleware_MTLSBoundSubjects426=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects427=== RUN TestService_ReadAuthMiddleware428=== PAUSE TestService_ReadAuthMiddleware429=== RUN TestService_AuthMiddleware_OIDC430=== PAUSE TestService_AuthMiddleware_OIDC431=== RUN TestService_RequireScope_OIDC432=== PAUSE TestService_RequireScope_OIDC433=== RUN TestService_ReadScope_PublicByDefault434=== PAUSE TestService_ReadScope_PublicByDefault435=== RUN TestCacheConfigHandler436=== PAUSE TestCacheConfigHandler437=== RUN TestCacheStatsHandler438=== PAUSE TestCacheStatsHandler439=== RUN TestClientCADerivations440=== PAUSE TestClientCADerivations441=== RUN TestClientErrorHandling442=== PAUSE TestClientErrorHandling443=== RUN TestClientIntegration444=== PAUSE TestClientIntegration445=== RUN TestClientMultipleUploads446=== PAUSE TestClientMultipleUploads447=== RUN TestClientWithDependencies448=== PAUSE TestClientWithDependencies449=== RUN TestClientSharedPathCommittedMidPush450=== PAUSE TestClientSharedPathCommittedMidPush451=== RUN TestPinProtectsFromGC452=== PAUSE TestPinProtectsFromGC453=== RUN TestResolveDBConnectionString454=== PAUSE TestResolveDBConnectionString455=== RUN TestLeadElectsOneAndHandsOver456=== PAUSE TestLeadElectsOneAndHandsOver457=== RUN TestLeadIncumbentWinsAfterRestart4582026-09-21 18:17:12.378 UTC [565] ERROR: relation "goose_db_version" does not exist at character 364592026-09-21 18:17:12.378 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4602026/09/21 18:17:12 OK 20241026095416_initial_model.sql (7.26ms)4612026/09/21 18:17:12 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)4622026/09/21 18:17:12 OK 20251218171726_add_pins.sql (2.17ms)4632026/09/21 18:17:12 OK 20260628120000_add_object_size_and_stats.sql (1.83ms)4642026/09/21 18:17:12 OK 20260905000000_add_claims.sql (2.33ms)4652026/09/21 18:17:12 OK 20260920000000_drop_claims.sql (1.37ms)4662026/09/21 18:17:12 goose: successfully migrated database to version: 202609200000004672026/09/21 18:17:12 OK 1_commit_pending_closure.sql (1.39ms)4682026/09/21 18:17:12 OK 2_object_stats_trigger.sql (714.68µs)4692026/09/21 18:17:12 goose: up to current file version: 24702026/09/21 18:17:12 INFO lead: acquired remote=192.0.2.1:12344712026/09/21 18:17:13 INFO lead: released remote=192.0.2.1:12344722026/09/21 18:17:13 INFO lead: acquired remote=192.0.2.1:12344732026/09/21 18:17:13 INFO lead: released remote=192.0.2.1:1234474--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)475=== RUN TestLeadEndsOnShutdown476=== PAUSE TestLeadEndsOnShutdown477=== RUN TestGCAdvisoryLockBlocksConcurrentRun4782026-09-21 18:17:13.146 UTC [575] ERROR: relation "goose_db_version" does not exist at character 364792026-09-21 18:17:13.146 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4802026/09/21 18:17:13 OK 20241026095416_initial_model.sql (6.73ms)4812026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)4822026/09/21 18:17:13 OK 20251218171726_add_pins.sql (2.45ms)4832026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (1.95ms)4842026/09/21 18:17:13 OK 20260905000000_add_claims.sql (2.28ms)4852026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (1.68ms)4862026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000004872026/09/21 18:17:13 OK 1_commit_pending_closure.sql (1.48ms)4882026/09/21 18:17:13 OK 2_object_stats_trigger.sql (788.83µs)4892026/09/21 18:17:13 goose: up to current file version: 2490--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)491=== RUN TestGCBugBareHashReferences492=== PAUSE TestGCBugBareHashReferences493=== RUN TestGCMetrics494=== PAUSE TestGCMetrics495=== RUN TestGCTaskStore_StartNew496=== PAUSE TestGCTaskStore_StartNew497=== RUN TestGCTaskStore_DeduplicateSameParams498=== PAUSE TestGCTaskStore_DeduplicateSameParams499=== RUN TestGCTaskStore_ConflictDifferentParams500=== PAUSE TestGCTaskStore_ConflictDifferentParams501=== RUN TestGCTaskStore_GetEmpty502=== PAUSE TestGCTaskStore_GetEmpty503=== RUN TestGCTaskStore_GetReturnsLatest504=== PAUSE TestGCTaskStore_GetReturnsLatest505=== RUN TestGCTaskStore_CompletedAllowsNewTask506=== PAUSE TestGCTaskStore_CompletedAllowsNewTask507=== RUN TestGCTaskStore_PhaseUpdates508=== PAUSE TestGCTaskStore_PhaseUpdates509=== RUN TestGCTaskStore_Fail510=== PAUSE TestGCTaskStore_Fail511=== RUN TestGracefulShutdownDrainsInflight512=== PAUSE TestGracefulShutdownDrainsInflight513=== RUN TestService_healthCheckHandler514=== PAUSE TestService_healthCheckHandler515=== RUN TestService_readinessHandler516=== PAUSE TestService_readinessHandler517=== RUN TestGenerateLandingPage518=== PAUSE TestGenerateLandingPage519=== RUN TestCacheConfigHandlerMaxNarSize520=== PAUSE TestCacheConfigHandlerMaxNarSize521=== RUN TestCreatePendingClosureRejectsOversizedNAR522=== PAUSE TestCreatePendingClosureRejectsOversizedNAR523=== RUN TestNARDeduplicationMetadataUploadBug524=== PAUSE TestNARDeduplicationMetadataUploadBug525=== RUN TestMetricsInventory526=== PAUSE TestMetricsInventory527=== RUN TestService_NativeMTLS528=== PAUSE TestService_NativeMTLS529=== RUN TestServerTLSConfig530=== PAUSE TestServerTLSConfig531=== RUN TestMultipartCleanup532=== PAUSE TestMultipartCleanup533=== RUN TestObjectStatsTrigger534=== PAUSE TestObjectStatsTrigger535=== RUN TestOrphanedObjectsGC536=== PAUSE TestOrphanedObjectsGC537=== RUN TestOrphanedObjectsGCStressTest538=== PAUSE TestOrphanedObjectsGCStressTest539=== RUN TestResurrectedObjectNotDeleted540=== PAUSE TestResurrectedObjectNotDeleted541=== RUN TestCreatePin_ReservedPins542=== PAUSE TestCreatePin_ReservedPins543=== RUN TestParseSingleRange544=== PAUSE TestParseSingleRange545=== RUN TestIsValidCachePath546=== PAUSE TestIsValidCachePath547=== RUN TestReadProxyNarinfo548=== PAUSE TestReadProxyNarinfo549=== RUN TestReadProxyNarinfoAlreadyDecompressed550=== PAUSE TestReadProxyNarinfoAlreadyDecompressed551=== RUN TestReadProxyNarStreaming552=== PAUSE TestReadProxyNarStreaming553=== RUN TestReadProxy404554=== PAUSE TestReadProxy404555=== RUN TestReadProxyInvalidPath556=== PAUSE TestReadProxyInvalidPath557=== RUN TestReadProxyHead558=== PAUSE TestReadProxyHead559=== RUN TestReadProxyConditionalGet560=== PAUSE TestReadProxyConditionalGet561=== RUN TestReadProxyRootRedirectsToIndexHTML562=== PAUSE TestReadProxyRootRedirectsToIndexHTML563=== RUN TestReadProxyDisabled564=== PAUSE TestReadProxyDisabled565=== RUN TestReadRedirectNar566=== PAUSE TestReadRedirectNar567=== RUN TestReadRedirectKeepsNarinfoProxied568=== PAUSE TestReadRedirectKeepsNarinfoProxied569=== RUN TestReadProxyRangeRequest570=== PAUSE TestReadProxyRangeRequest571=== RUN TestReadRedirectUsesPublicS3URL572=== PAUSE TestReadRedirectUsesPublicS3URL573=== RUN TestRedundantMultipartUpload574=== PAUSE TestRedundantMultipartUpload575=== RUN TestCompleteMultipartUpload_ErrorButObjectExists576=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists577=== RUN TestCompletedNarNotReofferedAcrossClosures578=== PAUSE TestCompletedNarNotReofferedAcrossClosures579=== RUN TestPresignedUploadRegisteredBeforeCommit580=== PAUSE TestPresignedUploadRegisteredBeforeCommit581=== RUN TestService_Rustfstest582=== PAUSE TestService_Rustfstest583=== RUN TestParseSize584=== PAUSE TestParseSize585=== RUN TestSkippedUploadsHandler586=== PAUSE TestSkippedUploadsHandler587=== RUN TestSystemdListenerNotActivated588--- PASS: TestSystemdListenerNotActivated (0.00s)589=== RUN TestWatchdogBeatsWhenHealthy590--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)591=== RUN TestWatchdogSkipsWhenUnhealthy5922026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5992026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6002026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6012026/09/21 18:17:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"602--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)603=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle604=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle605=== RUN TestProxyWriteTimeout606=== PAUSE TestProxyWriteTimeout607=== RUN TestIsValidUploadKey608=== PAUSE TestIsValidUploadKey609=== RUN TestUploadHandlersRejectInvalidKeys610=== PAUSE TestUploadHandlersRejectInvalidKeys611=== RUN TestUploadHandlersRejectOversizedBody612=== PAUSE TestUploadHandlersRejectOversizedBody613=== RUN TestService_cleanupPendingClosuresHandler614=== PAUSE TestService_cleanupPendingClosuresHandler615=== RUN TestService_createPendingClosureHandler616=== PAUSE TestService_createPendingClosureHandler617=== RUN TestService_verifyS3Integrity618=== PAUSE TestService_verifyS3Integrity619=== RUN TestCompleteMultipartUnregistered620=== PAUSE TestCompleteMultipartUnregistered621=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT622=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT623=== CONT TestService_AuthMiddleware624=== CONT TestMultipartCleanup625=== CONT TestGCTaskStore_StartNew626=== CONT TestGCMetrics627=== CONT TestServerTLSConfig628=== RUN TestServerTLSConfig/no_client_CA629=== CONT TestService_NativeMTLS630=== CONT TestMetricsInventory631=== CONT TestNARDeduplicationMetadataUploadBug632=== CONT TestCreatePendingClosureRejectsOversizedNAR633=== CONT TestCacheConfigHandlerMaxNarSize634=== CONT TestGenerateLandingPage6352026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures636=== CONT TestService_readinessHandler637=== CONT TestService_cleanupPendingClosuresHandler638=== CONT TestService_healthCheckHandler639=== CONT TestGracefulShutdownDrainsInflight640=== CONT TestGCTaskStore_Fail641=== CONT TestGCTaskStore_PhaseUpdates642=== CONT TestGCTaskStore_CompletedAllowsNewTask643=== CONT TestGCTaskStore_GetReturnsLatest644=== CONT TestGCTaskStore_GetEmpty645=== CONT TestGCTaskStore_ConflictDifferentParams646=== CONT TestGCTaskStore_DeduplicateSameParams647=== CONT TestReadProxyRangeRequest648=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT649=== CONT TestCompleteMultipartUnregistered650--- PASS: TestGCTaskStore_StartNew (0.00s)651=== CONT TestService_verifyS3Integrity652=== PAUSE TestServerTLSConfig/no_client_CA653=== CONT TestService_createPendingClosureHandler654=== CONT TestUploadHandlersRejectOversizedBody655=== CONT TestUploadHandlersRejectInvalidKeys656--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)657=== CONT TestIsValidUploadKey658=== CONT TestProxyWriteTimeout659=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle660=== CONT TestSkippedUploadsHandler661=== CONT TestParseSize662--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)663=== CONT TestClientErrorHandling664--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)665--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)666--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)667--- PASS: TestGCTaskStore_GetEmpty (0.00s)668--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)669--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)6702026/09/21 18:17:13 INFO Starting HTTP server address=127.0.0.1:33125671--- PASS: TestGCTaskStore_Fail (0.00s)6722026/09/21 18:17:13 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000673--- PASS: TestParseSize (0.00s)6742026/09/21 18:17:13 INFO Shutdown signal received, draining in-flight requests timeout=10s675--- PASS: TestGenerateLandingPage (0.01s)676=== CONT TestService_Rustfstest677--- PASS: TestSkippedUploadsHandler (0.01s)678=== CONT TestGCBugBareHashReferences679--- PASS: TestGracefulShutdownDrainsInflight (0.07s)680=== CONT TestPresignedUploadRegisteredBeforeCommit681=== RUN TestServerTLSConfig/missing_CA_file682=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info683=== RUN TestIsValidUploadKey/narinfo684=== RUN TestProxyWriteTimeout/narinfo685=== PAUSE TestIsValidUploadKey/narinfo686=== RUN TestIsValidUploadKey/nar_zst687=== PAUSE TestIsValidUploadKey/nar_zst688=== RUN TestIsValidUploadKey/nar_xz689=== PAUSE TestIsValidUploadKey/nar_xz690=== PAUSE TestServerTLSConfig/missing_CA_file691=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info692=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal693=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal694=== RUN TestServerTLSConfig/not_a_PEM_file695=== PAUSE TestServerTLSConfig/not_a_PEM_file696=== RUN TestClientErrorHandling/InvalidStorePath697=== RUN TestIsValidUploadKey/nar_plain698=== PAUSE TestClientErrorHandling/InvalidStorePath699=== PAUSE TestIsValidUploadKey/nar_plain700=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key701=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key702=== CONT TestCompletedNarNotReofferedAcrossClosures703=== PAUSE TestProxyWriteTimeout/narinfo704=== RUN TestProxyWriteTimeout/1_GiB_nar705=== PAUSE TestProxyWriteTimeout/1_GiB_nar706=== RUN TestProxyWriteTimeout/10_GiB_nar707=== RUN TestClientErrorHandling/InvalidAuthToken708=== RUN TestIsValidUploadKey/listing709=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key710=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key711=== PAUSE TestProxyWriteTimeout/10_GiB_nar712=== PAUSE TestClientErrorHandling/InvalidAuthToken713=== RUN TestClientErrorHandling/ServerNotAvailable714=== PAUSE TestClientErrorHandling/ServerNotAvailable715=== PAUSE TestIsValidUploadKey/listing716=== RUN TestIsValidUploadKey/build_log717=== PAUSE TestIsValidUploadKey/build_log718=== RUN TestIsValidUploadKey/build_log_home-manager_file719=== PAUSE TestIsValidUploadKey/build_log_home-manager_file720=== RUN TestIsValidUploadKey/build_log_plus_in_name721=== PAUSE TestIsValidUploadKey/build_log_plus_in_name722=== CONT TestLeadEndsOnShutdown723=== RUN TestProxyWriteTimeout/unknown_size724=== PAUSE TestProxyWriteTimeout/unknown_size725=== CONT TestCompleteMultipartUpload_ErrorButObjectExists726=== RUN TestIsValidUploadKey/build_log_question_mark727=== CONT TestLeadElectsOneAndHandsOver728=== PAUSE TestIsValidUploadKey/build_log_question_mark729=== RUN TestIsValidUploadKey/build_log_equals730=== PAUSE TestIsValidUploadKey/build_log_equals731=== RUN TestIsValidUploadKey/realisation732=== PAUSE TestIsValidUploadKey/realisation733=== RUN TestIsValidUploadKey/realisation_plus_in_output734=== PAUSE TestIsValidUploadKey/realisation_plus_in_output735=== RUN TestIsValidUploadKey/nix-cache-info736=== PAUSE TestIsValidUploadKey/nix-cache-info737=== RUN TestIsValidUploadKey/index.html738=== PAUSE TestIsValidUploadKey/index.html739=== RUN TestIsValidUploadKey/narinfo_key,_nar_type740=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type741=== RUN TestIsValidUploadKey/nar_key,_narinfo_type742=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type743=== RUN TestIsValidUploadKey/listing_key,_narinfo_type744=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type745=== RUN TestIsValidUploadKey/traversal746=== PAUSE TestIsValidUploadKey/traversal747=== RUN TestIsValidUploadKey/traversal_nar748=== PAUSE TestIsValidUploadKey/traversal_nar749=== RUN TestIsValidUploadKey/absolute750=== PAUSE TestIsValidUploadKey/absolute751=== RUN TestIsValidUploadKey/empty_key752=== PAUSE TestIsValidUploadKey/empty_key753=== RUN TestIsValidUploadKey/unknown_type754=== PAUSE TestIsValidUploadKey/unknown_type755=== CONT TestRedundantMultipartUpload7562026-09-21 18:17:13.632 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367572026-09-21 18:17:13.632 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026-09-21 18:17:13.642 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367592026-09-21 18:17:13.642 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC760=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart761=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart762=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts763=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts764=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure765=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure766=== CONT TestResolveDBConnectionString767=== RUN TestResolveDBConnectionString/flag_wins768=== PAUSE TestResolveDBConnectionString/flag_wins769=== RUN TestResolveDBConnectionString/file_when_flag_empty770=== PAUSE TestResolveDBConnectionString/file_when_flag_empty771=== RUN TestResolveDBConnectionString/missing_file_is_an_error772=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error773=== RUN TestResolveDBConnectionString/PGHOST_allows_empty774=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty775=== RUN TestResolveDBConnectionString/nothing_configured776=== PAUSE TestResolveDBConnectionString/nothing_configured777=== CONT TestReadRedirectUsesPublicS3URL7782026-09-21 18:17:13.659 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367792026-09-21 18:17:13.659 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026-09-21 18:17:13.706 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367812026-09-21 18:17:13.706 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7822026/09/21 18:17:13 OK 20241026095416_initial_model.sql (51.49ms)7832026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (4.85ms)7842026-09-21 18:17:13.726 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367852026-09-21 18:17:13.726 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/09/21 18:17:13 OK 20241026095416_initial_model.sql (54.09ms)7872026-09-21 18:17:13.729 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367882026-09-21 18:17:13.729 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026/09/21 18:17:13 OK 20241026095416_initial_model.sql (56.23ms)7902026/09/21 18:17:13 OK 20251218171726_add_pins.sql (9.61ms)7912026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (6.61ms)7922026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)7932026/09/21 18:17:13 OK 20251218171726_add_pins.sql (8.84ms)7942026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (10.56ms)7952026/09/21 18:17:13 OK 20251218171726_add_pins.sql (21.55ms)7962026/09/21 18:17:13 OK 20241026095416_initial_model.sql (33.84ms)7972026/09/21 18:17:13 OK 20260905000000_add_claims.sql (16.12ms)7982026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (22.82ms)7992026/09/21 18:17:13 OK 20241026095416_initial_model.sql (26.98ms)8002026/09/21 18:17:13 OK 20241026095416_initial_model.sql (25.75ms)8012026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (5.92ms)8022026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.81ms)8032026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (4.46ms)8042026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (5.45ms)8052026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008062026/09/21 18:17:13 OK 20260905000000_add_claims.sql (7.41ms)8072026/09/21 18:17:13 OK 20251218171726_add_pins.sql (6.69ms)8082026/09/21 18:17:13 OK 1_commit_pending_closure.sql (5.78ms)8092026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (4.73ms)8102026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008112026/09/21 18:17:13 OK 20251218171726_add_pins.sql (8.98ms)8122026/09/21 18:17:13 OK 20251218171726_add_pins.sql (10.82ms)8132026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (17.9ms)8142026-09-21 18:17:13.781 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368152026-09-21 18:17:13.781 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026-09-21 18:17:13.783 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368172026-09-21 18:17:13.783 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/09/21 18:17:13 OK 2_object_stats_trigger.sql (4.31ms)8192026/09/21 18:17:13 goose: up to current file version: 28202026-09-21 18:17:13.784 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368212026-09-21 18:17:13.784 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026/09/21 18:17:13 OK 1_commit_pending_closure.sql (5.47ms)8232026-09-21 18:17:13.786 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368242026-09-21 18:17:13.786 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8252026-09-21 18:17:13.786 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368262026-09-21 18:17:13.786 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8272026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)8282026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (8.71ms)8292026/09/21 18:17:13 OK 2_object_stats_trigger.sql (3.61ms)8302026/09/21 18:17:13 goose: up to current file version: 28312026/09/21 18:17:13 OK 20260905000000_add_claims.sql (8.1ms)8322026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (8.18ms)8332026/09/21 18:17:13 OK 20260905000000_add_claims.sql (5.93ms)8342026/09/21 18:17:13 OK 20260905000000_add_claims.sql (7.31ms)8352026/09/21 18:17:13 OK 20260905000000_add_claims.sql (5.52ms)8362026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (7.11ms)8372026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008382026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.23ms)8392026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008402026-09-21 18:17:13.800 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368412026-09-21 18:17:13.800 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (11.56ms)8432026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008442026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (11.57ms)8452026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008462026/09/21 18:17:13 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"847--- PASS: TestService_AuthMiddleware (0.37s)848=== CONT TestPinProtectsFromGC8492026-09-21 18:17:13.809 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368502026-09-21 18:17:13.809 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026/09/21 18:17:13 OK 1_commit_pending_closure.sql (14.14ms)8522026/09/21 18:17:13 OK 1_commit_pending_closure.sql (14.58ms)8532026/09/21 18:17:13 OK 20241026095416_initial_model.sql (17.75ms)8542026/09/21 18:17:13 OK 20241026095416_initial_model.sql (17.64ms)8552026/09/21 18:17:13 OK 1_commit_pending_closure.sql (7.15ms)8562026/09/21 18:17:13 OK 1_commit_pending_closure.sql (7.02ms)8572026/09/21 18:17:13 OK 2_object_stats_trigger.sql (3.59ms)8582026/09/21 18:17:13 OK 2_object_stats_trigger.sql (3.57ms)8592026/09/21 18:17:13 goose: up to current file version: 28602026/09/21 18:17:13 goose: up to current file version: 28612026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.33ms)8622026/09/21 18:17:13 goose: up to current file version: 28632026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)8642026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.51ms)8652026/09/21 18:17:13 goose: up to current file version: 28662026/09/21 18:17:13 OK 20241026095416_initial_model.sql (19.2ms)8672026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)8682026-09-21 18:17:13.817 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368692026-09-21 18:17:13.817 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026-09-21 18:17:13.819 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368712026-09-21 18:17:13.819 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)8732026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.62ms)8742026/09/21 18:17:13 OK 20251218171726_add_pins.sql (5.22ms)8752026/09/21 18:17:13 OK 20241026095416_initial_model.sql (17.3ms)8762026/09/21 18:17:13 OK 20251218171726_add_pins.sql (5.72ms)8772026-09-21 18:17:13.826 UTC [665] ERROR: relation "goose_db_version" does not exist at character 368782026-09-21 18:17:13.826 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026/09/21 18:17:13 OK 20241026095416_initial_model.sql (14.19ms)8802026-09-21 18:17:13.827 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368812026-09-21 18:17:13.827 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8822026-09-21 18:17:13.827 UTC [666] ERROR: relation "goose_db_version" does not exist at character 368832026-09-21 18:17:13.827 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8842026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)8852026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)8862026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)8872026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)8882026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)8892026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.05ms)8902026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.24ms)8912026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures8922026-09-21 18:17:13.832 UTC [667] ERROR: relation "goose_db_version" does not exist at character 368932026-09-21 18:17:13.832 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8942026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.42ms)8952026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.54ms)8962026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008972026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.85ms)8982026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000008992026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.66ms)9002026/09/21 18:17:13 OK 20251218171726_add_pins.sql (5.3ms)9012026/09/21 18:17:13 OK 20241026095416_initial_model.sql (18.41ms)9022026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.52ms)9032026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.75ms)9042026/09/21 18:17:13 OK 20241026095416_initial_model.sql (13.65ms)9052026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)9062026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (4.1ms)9072026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009082026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)9092026-09-21 18:17:13.839 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369102026-09-21 18:17:13.839 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9112026-09-21 18:17:13.839 UTC [669] ERROR: relation "goose_db_version" does not exist at character 369122026-09-21 18:17:13.839 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026-09-21 18:17:13.840 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369142026-09-21 18:17:13.840 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.29ms)9162026/09/21 18:17:13 goose: up to current file version: 29172026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.35ms)9182026/09/21 18:17:13 goose: up to current file version: 29192026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (6.2ms)9202026/09/21 18:17:13 OK 20241026095416_initial_model.sql (12.48ms)9212026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.78ms)9222026/09/21 18:17:13 OK 20260905000000_add_claims.sql (4.63ms)9232026/09/21 18:17:13 OK 20241026095416_initial_model.sql (12.89ms)9242026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.99ms)9252026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)9262026/09/21 18:17:13 OK 20251218171726_add_pins.sql (5.5ms)9272026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.86ms)9282026/09/21 18:17:13 goose: up to current file version: 29292026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)9302026/09/21 18:17:13 OK 20260905000000_add_claims.sql (4.2ms)9312026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.82ms)9322026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009332026/09/21 18:17:13 OK 20251218171726_add_pins.sql (5.02ms)9342026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.16ms)9352026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.78ms)9362026/09/21 18:17:13 OK 20241026095416_initial_model.sql (12.08ms)9372026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (4.04ms)9382026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009392026-09-21 18:17:13.851 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369402026-09-21 18:17:13.851 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9412026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.91ms)9422026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.51ms)9432026/09/21 18:17:13 OK 20241026095416_initial_model.sql (11.3ms)9442026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)9452026/09/21 18:17:13 OK 20241026095416_initial_model.sql (13.32ms)9462026/09/21 18:17:13 OK 20241026095416_initial_model.sql (13.07ms)9472026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.02ms)9482026/09/21 18:17:13 goose: up to current file version: 29492026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)9502026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)9512026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.28ms)9522026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)9532026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.54ms)9542026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)9552026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)9562026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.07ms)9572026/09/21 18:17:13 goose: up to current file version: 29582026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)9592026/09/21 18:17:13 OK 20260905000000_add_claims.sql (4.19ms)9602026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.48ms)9612026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009622026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.18ms)9632026-09-21 18:17:13.857 UTC [672] ERROR: relation "goose_db_version" does not exist at character 369642026-09-21 18:17:13.857 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9652026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.04ms)9662026/09/21 18:17:13 OK 20241026095416_initial_model.sql (9.99ms)9672026/09/21 18:17:13 OK 20260905000000_add_claims.sql (4.21ms)9682026/09/21 18:17:13 OK 20241026095416_initial_model.sql (11.39ms)9692026/09/21 18:17:13 OK 20241026095416_initial_model.sql (11.54ms)9702026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.04ms)9712026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009722026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.51ms)9732026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.84ms)9742026/09/21 18:17:13 OK 20251218171726_add_pins.sql (4.44ms)9752026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.4ms)9762026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)9772026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.76ms)9782026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009792026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)9802026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.18ms)9812026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)9822026/09/21 18:17:13 goose: up to current file version: 29832026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)9842026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)9852026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.7ms)9862026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000009872026/09/21 18:17:13 OK 20251218171726_add_pins.sql (2.91ms)9882026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.41ms)9892026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)9902026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.29ms)9912026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)9922026/09/21 18:17:13 OK 20251218171726_add_pins.sql (3.86ms)9932026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.58ms)9942026/09/21 18:17:13 goose: up to current file version: 29952026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3ms)9962026/09/21 18:17:13 OK 20251218171726_add_pins.sql (3.55ms)9972026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.77ms)9982026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.48ms)9992026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.75ms)10002026/09/21 18:17:13 goose: up to current file version: 210012026/09/21 18:17:13 OK 20241026095416_initial_model.sql (8.8ms)10022026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)10032026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.17ms)10042026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.03ms)10052026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.78ms)10062026/09/21 18:17:13 goose: up to current file version: 210072026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.3ms)10082026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010092026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)10102026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)10112026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.27ms)10122026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010132026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)10142026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.67ms)10152026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010162026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.87ms)10172026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010182026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.95ms)10192026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.79ms)10202026/09/21 18:17:13 OK 20251218171726_add_pins.sql (3.42ms)10212026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.92ms)10222026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.38ms)10232026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.92ms)10242026/09/21 18:17:13 goose: up to current file version: 210252026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.55ms)10262026/09/21 18:17:13 OK 1_commit_pending_closure.sql (3.22ms)10272026/09/21 18:17:13 OK 20260905000000_add_claims.sql (4.05ms)10282026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.33ms)10292026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010302026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.63ms)10312026/09/21 18:17:13 goose: up to current file version: 210322026/09/21 18:17:13 OK 20241026095416_initial_model.sql (9.96ms)10332026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.73ms)10342026/09/21 18:17:13 goose: up to current file version: 210352026/09/21 18:17:13 OK 2_object_stats_trigger.sql (2.05ms)10362026/09/21 18:17:13 goose: up to current file version: 210372026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)10382026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)10392026/09/21 18:17:13 OK 1_commit_pending_closure.sql (1.93ms)10402026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.79ms)10412026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010422026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (3.14ms)10432026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010442026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.46ms)10452026/09/21 18:17:13 goose: up to current file version: 210462026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.16ms)10472026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.76ms)10482026/09/21 18:17:13 OK 20251218171726_add_pins.sql (3.88ms)10492026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.82ms)10502026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.38ms)10512026/09/21 18:17:13 goose: up to current file version: 210522026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.23ms)10532026/09/21 18:17:13 goose: up to current file version: 210542026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.68ms)10552026/09/21 18:17:13 goose: successfully migrated database to version: 202609200000001056--- PASS: TestMetricsInventory (0.45s)10572026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)1058=== CONT TestClientSharedPathCommittedMidPush10592026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.2ms)10602026/09/21 18:17:13 OK 20260905000000_add_claims.sql (2.63ms)10612026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.41ms)10622026/09/21 18:17:13 goose: up to current file version: 210632026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.46ms)10642026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010652026/09/21 18:17:13 OK 1_commit_pending_closure.sql (1.86ms)10662026/09/21 18:17:13 OK 2_object_stats_trigger.sql (839.06µs)10672026/09/21 18:17:13 goose: up to current file version: 210682026/09/21 18:17:13 INFO Aborted multipart uploads count=010692026/09/21 18:17:13 WARN Force mode enabled - objects will be deleted immediately without grace period10702026/09/21 18:17:13 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=010712026/09/21 18:17:13 INFO Vacuumed table table=pending_closures10722026/09/21 18:17:13 INFO Vacuumed table table=pending_objects10732026/09/21 18:17:13 INFO Vacuumed table table=multipart_uploads10742026/09/21 18:17:13 INFO Vacuumed table table=closures10752026/09/21 18:17:13 INFO Vacuumed table table=objects10762026-09-21 18:17:13.903 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3610772026-09-21 18:17:13.903 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1078--- PASS: TestService_healthCheckHandler (0.47s)1079=== CONT TestClientWithDependencies1080--- PASS: TestGCMetrics (0.47s)1081=== CONT TestReadProxyNarStreaming10822026/09/21 18:17:13 OK 20241026095416_initial_model.sql (8.26ms)10832026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)10842026/09/21 18:17:13 OK 20251218171726_add_pins.sql (2.88ms)10852026/09/21 18:17:13 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)10862026/09/21 18:17:13 OK 20260905000000_add_claims.sql (3.23ms)10872026/09/21 18:17:13 INFO Received cleanup request method=DELETE path=/api/pending_closures10882026/09/21 18:17:13 OK 20260920000000_drop_claims.sql (2.93ms)10892026/09/21 18:17:13 goose: successfully migrated database to version: 2026092000000010902026/09/21 18:17:13 INFO Aborted multipart uploads count=010912026/09/21 18:17:13 OK 1_commit_pending_closure.sql (2.78ms)10922026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures10932026/09/21 18:17:13 OK 2_object_stats_trigger.sql (1.21ms)10942026/09/21 18:17:13 goose: up to current file version: 210952026/09/21 18:17:13 INFO Received cleanup request method=DELETE path=/api/pending_closures10962026/09/21 18:17:13 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10972026/09/21 18:17:13 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1098--- PASS: TestService_NativeMTLS (0.52s)1099=== CONT TestClientMultipleUploads11002026/09/21 18:17:13 INFO Aborted multipart uploads count=111012026/09/21 18:17:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11022026/09/21 18:17:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11032026-09-21 18:17:13.957 UTC [656] ERROR: Closure does not exist: id=111042026-09-21 18:17:13.957 UTC [656] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11052026-09-21 18:17:13.957 UTC [656] STATEMENT: -- name: CommitPendingClosure :exec1106 SELECT commit_pending_closure($1::bigint)1107 1108--- PASS: TestService_cleanupPendingClosuresHandler (0.52s)1109=== CONT TestClientIntegration11102026/09/21 18:17:13 INFO Aborted multipart uploads count=11111--- PASS: TestMultipartCleanup (0.53s)1112=== CONT TestReadRedirectKeepsNarinfoProxied1113=== NAME TestNARDeduplicationMetadataUploadBug1114 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug552302669/001/store/pgykv3rxxlri3gmfzminsyjmvsf3jwwp-file1.txt11152026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures11162026-09-21 18:17:13.974 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3611172026-09-21 18:17:13.974 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11182026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures11192026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures11202026/09/21 18:17:13 INFO Received uploads request method=POST path=/api/pending_closures11212026/09/21 18:17:13 OK 20241026095416_initial_model.sql (10.74ms)11222026/09/21 18:17:13 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)11232026-09-21 18:17:14.004 UTC [723] ERROR: relation "goose_db_version" does not exist at character 3611242026-09-21 18:17:14.004 UTC [723] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/09/21 18:17:14 OK 20251218171726_add_pins.sql (11.56ms)11262026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11272026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)11282026-09-21 18:17:14.011 UTC [724] ERROR: relation "goose_db_version" does not exist at character 3611292026-09-21 18:17:14.011 UTC [724] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11302026/09/21 18:17:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1131--- PASS: TestCompleteMultipartUnregistered (0.57s)1132=== CONT TestReadProxyHead11332026/09/21 18:17:14 OK 20260905000000_add_claims.sql (4.52ms)11342026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.85ms)11352026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000011362026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.54ms)11372026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.34ms)11382026/09/21 18:17:14 OK 2_object_stats_trigger.sql (2.12ms)11392026/09/21 18:17:14 goose: up to current file version: 211402026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)1141--- PASS: TestService_Rustfstest (0.58s)1142=== CONT TestReadProxyConditionalGet11432026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.22ms)11442026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.32ms)11452026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11462026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)11472026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)11482026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.12ms)11492026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.4ms)11502026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)11512026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (3.56ms)11522026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000011532026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.69ms)11542026/09/21 18:17:14 OK 20260905000000_add_claims.sql (4.58ms)11552026/09/21 18:17:14 OK 2_object_stats_trigger.sql (2.23ms)11562026/09/21 18:17:14 goose: up to current file version: 211572026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11582026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.95ms)11592026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000011602026/09/21 18:17:14 WARN readiness check failed error="closed pool"1161--- PASS: TestService_readinessHandler (0.61s)1162=== CONT TestReadProxyInvalidPath11632026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.55ms)11642026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.81ms)11652026/09/21 18:17:14 goose: up to current file version: 211662026-09-21 18:17:14.054 UTC [749] ERROR: relation "goose_db_version" does not exist at character 3611672026-09-21 18:17:14.054 UTC [749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11682026-09-21 18:17:14.062 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3611692026-09-21 18:17:14.062 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11702026-09-21 18:17:14.066 UTC [752] ERROR: relation "goose_db_version" does not exist at character 3611712026-09-21 18:17:14.066 UTC [752] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11722026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.83ms)11732026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)11742026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.12ms)11752026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)11762026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures11772026/09/21 18:17:14 OK 20241026095416_initial_model.sql (18.22ms)11782026/09/21 18:17:14 OK 20260905000000_add_claims.sql (11.72ms)11792026/09/21 18:17:14 OK 20241026095416_initial_model.sql (18.36ms)11802026/09/21 18:17:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11812026/09/21 18:17:14 INFO Uploading pgykv3rxxlri3gmfzminsyjmvsf3jwwp-file1.txt (160B)11822026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (5.01ms)11832026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)11842026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (3.26ms)11852026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000011862026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.51ms)11872026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.12ms)1188--- PASS: TestReadProxyRangeRequest (0.66s)1189=== CONT TestReadRedirectNar11902026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.71ms)11912026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.73ms)11922026/09/21 18:17:14 goose: up to current file version: 211932026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)11942026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11952026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)11962026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.71ms)11972026/09/21 18:17:14 WARN Failed to register uploaded object key=pgykv3rxxlri3gmfzminsyjmvsf3jwwp.ls error="server returned 404: 404 page not found\n"11982026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11992026/09/21 18:17:14 INFO Signed narinfos id=1 count=112002026/09/21 18:17:14 INFO Uploading 1 narinfos12012026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.99ms)12022026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (7.19ms)12032026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000012042026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (4.33ms)12052026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000012062026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.15ms)12072026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.68ms)12082026-09-21 18:17:14.112 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3612092026-09-21 18:17:14.112 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12102026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12112026/09/21 18:17:14 WARN Failed to register uploaded object key=pgykv3rxxlri3gmfzminsyjmvsf3jwwp.narinfo error="server returned 404: 404 page not found\n"12122026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.46ms)12132026/09/21 18:17:14 goose: up to current file version: 212142026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.78ms)12152026/09/21 18:17:14 goose: up to current file version: 212162026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12172026/09/21 18:17:14 INFO Completed upload id=112182026/09/21 18:17:14 INFO Upload complete. (114ms)1219=== NAME TestNARDeduplicationMetadataUploadBug1220 metadata_upload_test.go:54: Retrieved narinfo from S3:1221 StorePath: /build/TestNARDeduplicationMetadataUploadBug552302669/001/store/pgykv3rxxlri3gmfzminsyjmvsf3jwwp-file1.txt1222 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1223 Compression: zstd1224 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1225 NarSize: 1601226 References: 1227 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1228 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1229 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1230 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12312026/09/21 18:17:14 OK 20241026095416_initial_model.sql (7.9ms)12322026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)12332026-09-21 18:17:14.128 UTC [773] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-21 18:17:14.128 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.48ms)12362026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)1237--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.69s)1238=== CONT TestReadProxy40412392026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.79ms)12402026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.07ms)12412026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000012422026-09-21 18:17:14.139 UTC [775] ERROR: relation "goose_db_version" does not exist at character 3612432026-09-21 18:17:14.139 UTC [775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026/09/21 18:17:14 OK 20241026095416_initial_model.sql (7.8ms)12452026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.62ms)12462026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)12472026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.8ms)12482026/09/21 18:17:14 goose: up to current file version: 212492026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.53ms)12502026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12512026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)12522026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.35ms)12532026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.39ms)12542026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.64ms)12552026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000012562026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12572026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.53ms)12582026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.04ms)12592026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.85ms)12602026/09/21 18:17:14 goose: up to current file version: 21261=== NAME TestNARDeduplicationMetadataUploadBug1262 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug552302669/001/store/ddr2ca4ila79bh6pxh4sx96dihm08l8j-file2.txt12632026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)12642026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.3ms)12652026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.24ms)12662026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000012672026/09/21 18:17:14 OK 1_commit_pending_closure.sql (1.88ms)12682026/09/21 18:17:14 OK 2_object_stats_trigger.sql (701.34µs)12692026/09/21 18:17:14 goose: up to current file version: 212702026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12712026-09-21 18:17:14.182 UTC [795] ERROR: relation "goose_db_version" does not exist at character 3612722026-09-21 18:17:14.182 UTC [795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12732026/09/21 18:17:14 OK 20241026095416_initial_model.sql (7.71ms)12742026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)12752026/09/21 18:17:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12762026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12772026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.7ms)1278--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.69s)1279=== CONT TestReadProxyDisabled12802026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12812026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3ms)12822026/09/21 18:17:14 OK 20260905000000_add_claims.sql (9.37ms)12832026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (1.71ms)12842026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000012852026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.45ms)12862026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.35ms)12872026/09/21 18:17:14 goose: up to current file version: 212882026-09-21 18:17:14.224 UTC [817] ERROR: relation "goose_db_version" does not exist at character 3612892026-09-21 18:17:14.224 UTC [817] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12912026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12922026/09/21 18:17:14 OK 20241026095416_initial_model.sql (8.06ms)12932026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)12942026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.79ms)12952026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)12962026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures12972026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.82ms)12982026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.42ms)12992026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000013002026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.53ms)13012026/09/21 18:17:14 OK 2_object_stats_trigger.sql (935.84µs)13022026/09/21 18:17:14 goose: up to current file version: 213032026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures13042026/09/21 18:17:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13052026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13062026/09/21 18:17:14 WARN Failed to register uploaded object key=ddr2ca4ila79bh6pxh4sx96dihm08l8j.ls error="server returned 404: 404 page not found\n"13072026/09/21 18:17:14 INFO Signed narinfos id=2 count=113082026/09/21 18:17:14 INFO Uploading 1 narinfos13092026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13102026/09/21 18:17:14 WARN Failed to register uploaded object key=ddr2ca4ila79bh6pxh4sx96dihm08l8j.narinfo error="server returned 404: 404 page not found\n"13112026/09/21 18:17:14 INFO Completed upload id=213122026/09/21 18:17:14 INFO Upload complete. (86ms)1313--- PASS: TestReadRedirectUsesPublicS3URL (0.64s)13142026-09-21 18:17:14.281 UTC [854] ERROR: relation "goose_db_version" does not exist at character 3613152026-09-21 18:17:14.281 UTC [854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1316=== CONT TestReadProxyRootRedirectsToIndexHTML1317=== NAME TestNARDeduplicationMetadataUploadBug1318 metadata_upload_test.go:76: Retrieved narinfo from S3:1319 StorePath: /build/TestNARDeduplicationMetadataUploadBug552302669/001/store/ddr2ca4ila79bh6pxh4sx96dihm08l8j-file2.txt1320 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1321 Compression: zstd1322 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1323 NarSize: 1601324 References: 1325 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13262026/09/21 18:17:14 INFO lead: acquired remote=192.0.2.1:12341327 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1328 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1329 {"version":1,"root":{"type":"regular","size":44}}1330--- PASS: TestNARDeduplicationMetadataUploadBug (0.85s)1331=== CONT TestService_RequireScope_OIDC13322026/09/21 18:17:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43689/oidc13332026/09/21 18:17:14 OK 20241026095416_initial_model.sql (6.88ms)13342026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (847.75µs)13352026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.51ms)13362026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)13372026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.9ms)13382026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.47ms)13392026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000013402026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.28ms)13412026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.9ms)13422026/09/21 18:17:14 goose: up to current file version: 21343--- PASS: TestGCBugBareHashReferences (0.86s)1344=== CONT TestService_ReadAuthMiddleware13452026/09/21 18:17:14 INFO lead: acquired remote=192.0.2.1:123413462026/09/21 18:17:14 INFO lead: released remote=192.0.2.1:12341347--- PASS: TestLeadEndsOnShutdown (0.74s)1348=== CONT TestService_AuthMiddleware_OIDC13492026/09/21 18:17:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35187/oidc13502026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures13512026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13522026-09-21 18:17:14.390 UTC [865] ERROR: relation "goose_db_version" does not exist at character 3613532026-09-21 18:17:14.390 UTC [865] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13542026/09/21 18:17:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNjMTA5NTUtZGQ3ZC00NDQ1LThlNTItN2JiN2YxZmRjZDI3LjZmYzM4ZDJhLTA3ZDMtNGYyNS1iZDc1LTZlYTlkZDMxNjI2NHgxNzkwMDE0NjM0MzU2MTc0MDU513552026-09-21 18:17:14.393 UTC [866] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-21 18:17:14.393 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13572026/09/21 18:17:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNjMTA5NTUtZGQ3ZC00NDQ1LThlNTItN2JiN2YxZmRjZDI3LjZmYzM4ZDJhLTA3ZDMtNGYyNS1iZDc1LTZlYTlkZDMxNjI2NHgxNzkwMDE0NjM0MzU2MTc0MDU5 parts=11358--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.83s)1359=== CONT TestClientCADerivations13602026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.27ms)13612026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.53ms)13622026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)13632026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)13642026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.42ms)13652026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.9ms)13662026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)13672026-09-21 18:17:14.417 UTC [886] ERROR: relation "goose_db_version" does not exist at character 3613682026-09-21 18:17:14.417 UTC [886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13692026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)13702026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.92ms)13712026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.62ms)13722026-09-21 18:17:14.421 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3613732026-09-21 18:17:14.421 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13742026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000013752026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.68ms)13762026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.13ms)13772026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.82ms)13782026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000013792026/09/21 18:17:14 OK 2_object_stats_trigger.sql (714.58µs)13802026/09/21 18:17:14 goose: up to current file version: 213812026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.18ms)13822026/09/21 18:17:14 OK 2_object_stats_trigger.sql (2.12ms)13832026/09/21 18:17:14 goose: up to current file version: 213842026/09/21 18:17:14 OK 20241026095416_initial_model.sql (8.67ms)13852026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)13862026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.29ms)13872026/09/21 18:17:14 INFO lead: released remote=192.0.2.1:123413882026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)13892026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.83ms)13902026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.85ms)13912026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (2.92ms)13922026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)13932026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.24ms)13942026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (1.76ms)13952026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000013962026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.29ms)13972026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.09ms)13982026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.26ms)13992026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000014002026/09/21 18:17:14 OK 2_object_stats_trigger.sql (734.3µs)14012026/09/21 18:17:14 goose: up to current file version: 214022026/09/21 18:17:14 OK 1_commit_pending_closure.sql (1.56ms)14032026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.15ms)14042026/09/21 18:17:14 goose: up to current file version: 214052026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1406=== NAME TestPinProtectsFromGC1407 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1932552864/001/store/g97n3jn0nm6xrakjl1k2igbyg0y0xrpn-pinned-file.txt1408 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1932552864/001/store/nsa4sswc72d2gf2830nzw8bj5bjn1phy-unpinned-file.txt14092026/09/21 18:17:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjNjMTA5NTUtZGQ3ZC00NDQ1LThlNTItN2JiN2YxZmRjZDI3LjZkNmNjOTJjLTJjMjUtNGNjZi1iOWQxLTI4NjRiOWNjN2E2NngxNzkwMDE0NjM0MDA1OTc2ODE5 parts=1014102026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1411--- PASS: TestReadProxyNarStreaming (0.57s)1412=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14132026/09/21 18:17:14 INFO Completed upload id=114142026/09/21 18:17:14 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014152026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures14162026/09/21 18:17:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures14172026/09/21 18:17:14 INFO lead: acquired remote=192.0.2.1:123414182026-09-21 18:17:14.487 UTC [990] ERROR: relation "goose_db_version" does not exist at character 3614192026-09-21 18:17:14.487 UTC [990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14202026/09/21 18:17:14 INFO lead: released remote=192.0.2.1:12341421--- PASS: TestLeadElectsOneAndHandsOver (0.92s)1422=== CONT TestCacheStatsHandler14232026/09/21 18:17:14 INFO Aborted multipart uploads count=014242026/09/21 18:17:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=014252026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.41ms)14262026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)14272026/09/21 18:17:14 INFO Vacuumed table table=pending_closures14282026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.05ms)14292026/09/21 18:17:14 INFO Vacuumed table table=pending_objects14302026/09/21 18:17:14 INFO Vacuumed table table=multipart_uploads14312026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)14322026/09/21 18:17:14 INFO Vacuumed table table=closures14332026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.64ms)14342026/09/21 18:17:14 INFO Vacuumed table table=objects14352026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.25ms)14362026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000014372026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.65ms)14382026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.72ms)14392026/09/21 18:17:14 goose: up to current file version: 214402026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1441=== NAME TestClientWithDependencies1442 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1297694422/001/store/x05y4851by046sx22l56f2999kfji67r-test-script14432026/09/21 18:17:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001444--- PASS: TestService_createPendingClosureHandler (1.10s)1445=== CONT TestCacheConfigHandler1446=== RUN TestCacheConfigHandler/full_config,_no_issuer1447=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1448=== RUN TestCacheConfigHandler/no_cache_url_configured1449=== PAUSE TestCacheConfigHandler/no_cache_url_configured1450=== RUN TestCacheConfigHandler/no_signing_keys1451=== PAUSE TestCacheConfigHandler/no_signing_keys1452=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1453=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1454=== CONT TestService_ReadScope_PublicByDefault1455=== NAME TestClientMultipleUploads1456 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2784490849/001/store/dk36rn5g63z8qllkmfz0c28lmd423qzd-test-file-0.txt1457=== NAME TestClientWithDependencies1458 client_integration_test.go:615: Found 1 dependencies (including self)1459--- PASS: TestReadRedirectKeepsNarinfoProxied (0.60s)1460=== CONT TestResurrectedObjectNotDeleted14612026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures1462=== NAME TestClientIntegration1463 client_integration_test.go:286: Created store path: /build/TestClientIntegration3880967724/002/store/yv8ayb132jm3dmx1d0kz06hiyfav0diq-test-file.txt14642026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1465=== NAME TestClientMultipleUploads1466 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2784490849/001/store/ng56r8gw94pwdffm0l9820g45igqvjwg-test-file-1.txt14672026/09/21 18:17:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14682026/09/21 18:17:14 INFO Uploading g97n3jn0nm6xrakjl1k2igbyg0y0xrpn-pinned-file.txt (128B)14692026-09-21 18:17:14.575 UTC [1160] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-21 18:17:14.575 UTC [1160] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14712026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14722026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14732026/09/21 18:17:14 WARN Failed to register uploaded object key=g97n3jn0nm6xrakjl1k2igbyg0y0xrpn.ls error="server returned 404: 404 page not found\n"14742026/09/21 18:17:14 INFO Signed narinfos id=1 count=114752026/09/21 18:17:14 INFO Uploading 1 narinfos1476--- PASS: TestReadProxyHead (0.58s)1477=== CONT TestOrphanedObjectsGCStressTest14782026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14792026/09/21 18:17:14 WARN Failed to register uploaded object key=g97n3jn0nm6xrakjl1k2igbyg0y0xrpn.narinfo error="server returned 404: 404 page not found\n"14802026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.1ms)14812026-09-21 18:17:14.591 UTC [1163] ERROR: relation "goose_db_version" does not exist at character 3614822026-09-21 18:17:14.591 UTC [1163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14832026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)14842026/09/21 18:17:14 OK 20251218171726_add_pins.sql (4.08ms)14852026/09/21 18:17:14 INFO Completed upload id=114862026/09/21 18:17:14 INFO Upload complete. (111ms)14872026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)14882026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.81ms)1489=== NAME TestClientMultipleUploads1490 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2784490849/001/store/im95n36c3ij5hwb2zj8cmdips6h5ph5m-test-file-2.txt14912026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures14922026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.65ms)14932026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000014942026/09/21 18:17:14 OK 20241026095416_initial_model.sql (9.72ms)14952026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2ms)14962026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.85ms)14972026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.44ms)14982026/09/21 18:17:14 goose: up to current file version: 214992026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.87ms)15002026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)1501--- PASS: TestReadProxyConditionalGet (0.59s)1502=== CONT TestOrphanedObjectsGC15032026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.8ms)15042026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.69ms)15052026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000015062026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.42ms)15072026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.97ms)15082026/09/21 18:17:14 goose: up to current file version: 215092026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15102026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures1511--- PASS: TestReadProxyInvalidPath (0.59s)1512=== CONT TestReadProxyNarinfo15132026-09-21 18:17:14.642 UTC [1292] ERROR: relation "goose_db_version" does not exist at character 3615142026-09-21 18:17:14.642 UTC [1292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026/09/21 18:17:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15162026/09/21 18:17:14 INFO Uploading x05y4851by046sx22l56f2999kfji67r-test-script (136B)15172026/09/21 18:17:14 WARN Failed to register uploaded object key=log/n3c7b59pqp6gzb4x7xp1fx7a1pf146p6-test-script.drv error="server returned 404: 404 page not found\n"15182026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15192026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15202026/09/21 18:17:14 WARN Failed to register uploaded object key=x05y4851by046sx22l56f2999kfji67r.ls error="server returned 404: 404 page not found\n"15212026/09/21 18:17:14 INFO Signed narinfos id=1 count=115222026/09/21 18:17:14 INFO Uploading 1 narinfos15232026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15242026/09/21 18:17:14 WARN Failed to register uploaded object key=x05y4851by046sx22l56f2999kfji67r.narinfo error="server returned 404: 404 page not found\n"15252026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15262026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.22ms)15272026-09-21 18:17:14.667 UTC [1349] ERROR: relation "goose_db_version" does not exist at character 3615282026-09-21 18:17:14.667 UTC [1349] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15292026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15302026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)15312026/09/21 18:17:14 INFO Completed upload id=115322026/09/21 18:17:14 INFO Upload complete. (72ms)1533--- PASS: TestReadRedirectNar (0.58s)1534=== CONT TestCreatePin_ReservedPins15352026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.99ms)1536=== NAME TestClientWithDependencies1537 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1297694422/001/store) requires matching store prefix15382026/09/21 18:17:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40687/oidc15392026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)1540--- PASS: TestClientWithDependencies (0.77s)1541=== CONT TestReadProxyNarinfoAlreadyDecompressed15422026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15432026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.64ms)15442026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15452026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.07ms)15462026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (3.62ms)15472026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000015482026-09-21 18:17:14.685 UTC [1391] ERROR: relation "goose_db_version" does not exist at character 3615492026-09-21 18:17:14.685 UTC [1391] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15502026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)15512026/09/21 18:17:14 OK 1_commit_pending_closure.sql (1.82ms)15522026/09/21 18:17:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15532026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.54ms)15542026/09/21 18:17:14 goose: up to current file version: 215552026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.33ms)15562026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (2.93ms)1557--- PASS: TestReadProxy404 (0.56s)1558=== CONT TestParseSingleRange1559=== RUN TestParseSingleRange/none1560=== PAUSE TestParseSingleRange/none1561=== RUN TestParseSingleRange/unknown_unit1562=== PAUSE TestParseSingleRange/unknown_unit1563=== RUN TestParseSingleRange/multi-range_ignored1564=== PAUSE TestParseSingleRange/multi-range_ignored1565=== RUN TestParseSingleRange/malformed_no_dash1566=== PAUSE TestParseSingleRange/malformed_no_dash1567=== RUN TestParseSingleRange/malformed_both_empty1568=== PAUSE TestParseSingleRange/malformed_both_empty1569=== RUN TestParseSingleRange/malformed_end_before_start1570=== PAUSE TestParseSingleRange/malformed_end_before_start1571=== RUN TestParseSingleRange/closed1572=== PAUSE TestParseSingleRange/closed1573=== RUN TestParseSingleRange/open-ended1574=== PAUSE TestParseSingleRange/open-ended1575=== RUN TestParseSingleRange/end_clamped_to_size1576=== PAUSE TestParseSingleRange/end_clamped_to_size1577=== RUN TestParseSingleRange/suffix1578=== PAUSE TestParseSingleRange/suffix1579=== RUN TestParseSingleRange/suffix_exceeds_size1580=== PAUSE TestParseSingleRange/suffix_exceeds_size1581=== RUN TestParseSingleRange/single_byte1582=== PAUSE TestParseSingleRange/single_byte1583=== RUN TestParseSingleRange/start_past_EOF1584=== PAUSE TestParseSingleRange/start_past_EOF1585=== RUN TestParseSingleRange/start_far_past_EOF1586=== PAUSE TestParseSingleRange/start_far_past_EOF1587=== CONT TestObjectStatsTrigger15882026/09/21 18:17:14 OK 20260905000000_add_claims.sql (5ms)15892026/09/21 18:17:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjNjMTA5NTUtZGQ3ZC00NDQ1LThlNTItN2JiN2YxZmRjZDI3LjY3NzdkZDY2LTA4YjMtNGQ2YS1iNjllLWY3ODdlNzA3NGRmOHgxNzkwMDE0NjM0MjE1NzM2NTAz parts=1015902026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15912026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.96ms)15922026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000015932026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures15942026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.09ms)15952026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures15962026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.13ms)15972026/09/21 18:17:14 INFO Completed upload id=115982026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)15992026/09/21 18:17:14 OK 2_object_stats_trigger.sql (2.13ms)16002026/09/21 18:17:14 goose: up to current file version: 216012026/09/21 18:17:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16022026/09/21 18:17:14 INFO Uploading nsa4sswc72d2gf2830nzw8bj5bjn1phy-unpinned-file.txt (128B)16032026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures16042026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.22ms)16052026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures16062026/09/21 18:17:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16072026/09/21 18:17:14 INFO Uploading yv8ayb132jm3dmx1d0kz06hiyfav0diq-test-file.txt (152B)16082026/09/21 18:17:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16092026/09/21 18:17:14 WARN Found objects in DB but missing from S3, will re-upload count=116102026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1611--- PASS: TestService_verifyS3Integrity (1.27s)16122026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)1613=== CONT TestService_AuthMiddleware_MTLSProxyHeader16142026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16152026/09/21 18:17:14 WARN Failed to register uploaded object key=nsa4sswc72d2gf2830nzw8bj5bjn1phy.ls error="server returned 404: 404 page not found\n"16162026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16172026/09/21 18:17:14 INFO Signed narinfos id=2 count=116182026/09/21 18:17:14 INFO Uploading 1 narinfos16192026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.87ms)16202026/09/21 18:17:14 WARN Failed to register uploaded object key=yv8ayb132jm3dmx1d0kz06hiyfav0diq.ls error="server returned 404: 404 page not found\n"16212026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16222026/09/21 18:17:14 INFO Signed narinfos id=1 count=116232026/09/21 18:17:14 INFO Uploading 1 narinfos1624--- PASS: TestReadProxyDisabled (0.52s)1625=== CONT TestIsValidCachePath1626=== RUN TestIsValidCachePath/narinfo1627=== PAUSE TestIsValidCachePath/narinfo1628=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1629=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1630=== RUN TestIsValidCachePath/nar_zst1631=== PAUSE TestIsValidCachePath/nar_zst1632=== RUN TestIsValidCachePath/nar_xz1633=== PAUSE TestIsValidCachePath/nar_xz1634=== RUN TestIsValidCachePath/nar_bz216352026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.91ms)1636=== PAUSE TestIsValidCachePath/nar_bz216372026/09/21 18:17:14 goose: successfully migrated database to version: 202609200000001638=== RUN TestIsValidCachePath/nar_uncompressed16392026/09/21 18:17:14 WARN Failed to register uploaded object key=nsa4sswc72d2gf2830nzw8bj5bjn1phy.narinfo error="server returned 404: 404 page not found\n"1640=== PAUSE TestIsValidCachePath/nar_uncompressed16412026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1642=== RUN TestIsValidCachePath/ls1643=== PAUSE TestIsValidCachePath/ls1644=== RUN TestIsValidCachePath/log1645=== PAUSE TestIsValidCachePath/log16462026-09-21 18:17:14.720 UTC [1445] ERROR: relation "goose_db_version" does not exist at character 3616472026-09-21 18:17:14.720 UTC [1445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1648=== RUN TestIsValidCachePath/realisation1649=== PAUSE TestIsValidCachePath/realisation1650=== RUN TestIsValidCachePath/nix-cache-info1651=== PAUSE TestIsValidCachePath/nix-cache-info16522026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures1653=== RUN TestIsValidCachePath/index.html1654=== PAUSE TestIsValidCachePath/index.html1655=== RUN TestIsValidCachePath/traversal_parent1656=== PAUSE TestIsValidCachePath/traversal_parent1657=== RUN TestIsValidCachePath/traversal_in_middle1658=== PAUSE TestIsValidCachePath/traversal_in_middle1659=== RUN TestIsValidCachePath/invalid_char_e1660=== PAUSE TestIsValidCachePath/invalid_char_e1661=== RUN TestIsValidCachePath/invalid_char_u1662=== PAUSE TestIsValidCachePath/invalid_char_u1663=== RUN TestIsValidCachePath/random_path1664=== PAUSE TestIsValidCachePath/random_path1665=== RUN TestIsValidCachePath/empty1666=== PAUSE TestIsValidCachePath/empty1667=== RUN TestIsValidCachePath/leading_slash1668=== PAUSE TestIsValidCachePath/leading_slash1669=== RUN TestIsValidCachePath/wrong_extension1670=== PAUSE TestIsValidCachePath/wrong_extension1671=== RUN TestIsValidCachePath/short_hash1672=== PAUSE TestIsValidCachePath/short_hash1673=== CONT TestServerTLSConfig/no_client_CA1674=== CONT TestServerTLSConfig/not_a_PEM_file16752026/09/21 18:17:14 INFO Completed upload id=216762026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.28ms)16772026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16782026/09/21 18:17:14 INFO Upload complete. (89ms)16792026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16802026/09/21 18:17:14 WARN Failed to register uploaded object key=yv8ayb132jm3dmx1d0kz06hiyfav0diq.narinfo error="server returned 404: 404 page not found\n"1681=== CONT TestServerTLSConfig/missing_CA_file1682--- PASS: TestServerTLSConfig (0.13s)1683 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1684 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1685 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1686=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16872026/09/21 18:17:14 INFO Received uploads request method=POST path=/1688=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16892026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/1690=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16912026/09/21 18:17:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16922026/09/21 18:17:14 INFO Received uploads request method=POST path=/16932026/09/21 18:17:14 INFO Uploading dwr16yxn72iff0cd8nw392bilr5rd8qa-shared-dep (136B)1694=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16952026/09/21 18:17:14 INFO Received request for more parts method=POST path=/16962026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.72ms)1697--- PASS: TestUploadHandlersRejectInvalidKeys (0.13s)1698 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1699 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1700 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1701 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)17022026/09/21 18:17:14 goose: up to current file version: 21703=== CONT TestClientErrorHandling/InvalidStorePath17042026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17052026/09/21 18:17:14 INFO Completed upload id=117062026/09/21 18:17:14 INFO Upload complete. (106ms)17072026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17082026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures17092026/09/21 18:17:14 WARN Failed to register uploaded object key=dwr16yxn72iff0cd8nw392bilr5rd8qa.ls error="server returned 404: 404 page not found\n"17102026/09/21 18:17:14 INFO Signed narinfos id=2 count=117112026/09/21 18:17:14 INFO Uploading 1 narinfos17122026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17132026/09/21 18:17:14 WARN Failed to register uploaded object key=dwr16yxn72iff0cd8nw392bilr5rd8qa.narinfo error="server returned 404: 404 page not found\n"1714--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)1715=== CONT TestClientErrorHandling/ServerNotAvailable17162026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures17172026/09/21 18:17:14 INFO Completed upload id=217182026/09/21 18:17:14 OK 20241026095416_initial_model.sql (23.94ms)17192026/09/21 18:17:14 INFO Upload complete. (100ms)17202026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures17212026/09/21 18:17:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjNjMTA5NTUtZGQ3ZC00NDQ1LThlNTItN2JiN2YxZmRjZDI3LjZkYmQ4NmIyLTU3YzEtNDRmYy1iNzk0LWU4OTcyYmIzNTY4YXgxNzkwMDE0NjM0MTU4MDI4OTk4 parts=1217222026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures17232026/09/21 18:17:14 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17242026/09/21 18:17:14 INFO Received uploads request method=POST path=/api/pending_closures17252026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)17262026/09/21 18:17:14 INFO Uploading dwr16yxn72iff0cd8nw392bilr5rd8qa-shared-dep (136B)17272026/09/21 18:17:14 INFO Uploading p7swawb3z089l6wkjzdqgfrcnr1c121m-top (224B)17282026/09/21 18:17:14 INFO Received create pin request method=POST path=/api/pins/myapp17292026/09/21 18:17:14 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17302026/09/21 18:17:14 INFO Uploading im95n36c3ij5hwb2zj8cmdips6h5ph5m-test-file-2.txt (160B)17312026/09/21 18:17:14 INFO Uploading ng56r8gw94pwdffm0l9820g45igqvjwg-test-file-1.txt (160B)17322026/09/21 18:17:14 INFO Uploading dk36rn5g63z8qllkmfz0c28lmd423qzd-test-file-0.txt (160B)1733--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.19s)1734=== CONT TestClientErrorHandling/InvalidAuthToken17352026/09/21 18:17:14 OK 20251218171726_add_pins.sql (4.81ms)17362026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17372026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/0zwzshp4l56bw1lz6xmnxjcsryrgrlfh0lqra22bz10zzkj53ivh.nar.zst error="server returned 404: 404 page not found\n"17382026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17392026-09-21 18:17:14.763 UTC [1509] ERROR: relation "goose_db_version" does not exist at character 3617402026-09-21 18:17:14.763 UTC [1509] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17412026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17422026/09/21 18:17:14 WARN Failed to register uploaded object key=dwr16yxn72iff0cd8nw392bilr5rd8qa.ls error="server returned 404: 404 page not found\n"17432026/09/21 18:17:14 WARN Failed to register uploaded object key=p7swawb3z089l6wkjzdqgfrcnr1c121m.ls error="server returned 404: 404 page not found\n"17442026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17452026/09/21 18:17:14 INFO Signed narinfos id=1 count=117462026/09/21 18:17:14 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17472026/09/21 18:17:14 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1932552864/001/store/g97n3jn0nm6xrakjl1k2igbyg0y0xrpn-pinned-file.txt narinfo_key=g97n3jn0nm6xrakjl1k2igbyg0y0xrpn.narinfo17482026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign17492026/09/21 18:17:14 INFO Signed narinfos id=3 count=117502026/09/21 18:17:14 INFO Uploading 2 narinfos17512026/09/21 18:17:14 WARN Failed to register uploaded object key=im95n36c3ij5hwb2zj8cmdips6h5ph5m.ls error="server returned 404: 404 page not found\n"17522026/09/21 18:17:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures17532026/09/21 18:17:14 INFO Garbage collection started17542026/09/21 18:17:14 INFO All 1 paths already cached17552026/09/21 18:17:14 WARN Failed to register uploaded object key=ng56r8gw94pwdffm0l9820g45igqvjwg.ls error="server returned 404: 404 page not found\n"1756=== NAME TestClientIntegration1757 client_integration_test.go:312: Retrieved narinfo from S3:17582026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign1759 StorePath: /build/TestClientIntegration3880967724/002/store/yv8ayb132jm3dmx1d0kz06hiyfav0diq-test-file.txt1760 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1761 Compression: zstd1762 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11763 NarSize: 1521764 References: 1765 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117662026/09/21 18:17:14 WARN Failed to register uploaded object key=dk36rn5g63z8qllkmfz0c28lmd423qzd.ls error="server returned 404: 404 page not found\n"17672026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (8.92ms)17682026/09/21 18:17:14 INFO Signed narinfos id=3 count=117692026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17702026/09/21 18:17:14 INFO Signed narinfos id=1 count=117712026/09/21 18:17:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17722026/09/21 18:17:14 INFO Signed narinfos id=2 count=117732026/09/21 18:17:14 INFO Uploading 3 narinfos1774 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)17752026/09/21 18:17:14 WARN Failed to register uploaded object key=dwr16yxn72iff0cd8nw392bilr5rd8qa.narinfo error="server returned 404: 404 page not found\n"1776 client_integration_test.go:313: Decompressed .ls content (64 bytes):1777 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1778 client_integration_test.go:316: Testing garbage collection...17792026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17802026/09/21 18:17:14 WARN Failed to register uploaded object key=p7swawb3z089l6wkjzdqgfrcnr1c121m.narinfo error="server returned 404: 404 page not found\n"17812026/09/21 18:17:14 WARN Failed to register uploaded object key=im95n36c3ij5hwb2zj8cmdips6h5ph5m.narinfo error="server returned 404: 404 page not found\n"17822026/09/21 18:17:14 INFO Completed upload id=117832026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17842026/09/21 18:17:14 WARN Failed to register uploaded object key=ng56r8gw94pwdffm0l9820g45igqvjwg.narinfo error="server returned 404: 404 page not found\n"17852026/09/21 18:17:14 WARN Failed to register uploaded object key=dk36rn5g63z8qllkmfz0c28lmd423qzd.narinfo error="server returned 404: 404 page not found\n"17862026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17872026/09/21 18:17:14 OK 20260905000000_add_claims.sql (8.54ms)17882026/09/21 18:17:14 INFO Aborted multipart uploads count=017892026/09/21 18:17:14 INFO Completed upload id=317902026/09/21 18:17:14 INFO Upload complete. (249ms)1791=== NAME TestClientSharedPathCommittedMidPush1792 client_integration_test.go:680: Retrieved narinfo from S3:1793 StorePath: /build/TestClientSharedPathCommittedMidPush995804677/001/store/dwr16yxn72iff0cd8nw392bilr5rd8qa-shared-dep1794 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1795 Compression: zstd1796 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821797 NarSize: 1361798 References: 1799 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18002026/09/21 18:17:14 OK 20241026095416_initial_model.sql (10.03ms)1801 client_integration_test.go:680: Retrieved narinfo from S3:1802 StorePath: /build/TestClientSharedPathCommittedMidPush995804677/001/store/p7swawb3z089l6wkjzdqgfrcnr1c121m-top1803 URL: nar/0zwzshp4l56bw1lz6xmnxjcsryrgrlfh0lqra22bz10zzkj53ivh.nar.zst1804 Compression: zstd1805 NarHash: sha256:0zwzshp4l56bw1lz6xmnxjcsryrgrlfh0lqra22bz10zzkj53ivh1806 NarSize: 2241807 References: /build/TestClientSharedPathCommittedMidPush995804677/001/store/dwr16yxn72iff0cd8nw392bilr5rd8qa-shared-dep18082026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (4.36ms)1809 CA: text:sha256:14pv5y4blmbk3457gafpd0l973pwz84hckgf464c2v4j0h1h0cvg18102026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000018112026/09/21 18:17:14 WARN Force mode enabled - objects will be deleted immediately without grace period18122026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)1813=== RUN TestService_RequireScope_OIDC/builder_may_write1814=== PAUSE TestService_RequireScope_OIDC/builder_may_write1815=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1816=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1817=== RUN TestService_RequireScope_OIDC/ops_may_admin18182026/09/21 18:17:14 INFO Completed upload id=21819=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1820=== RUN TestService_RequireScope_OIDC/ops_may_not_write1821=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1822=== RUN TestService_RequireScope_OIDC/reader_may_not_write1823=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write18242026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1825=== RUN TestService_RequireScope_OIDC/static_token_may_admin1826=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1827=== RUN TestService_RequireScope_OIDC/static_token_may_write1828=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1829=== RUN TestService_RequireScope_OIDC/reader_may_read1830=== PAUSE TestService_RequireScope_OIDC/reader_may_read1831=== RUN TestService_RequireScope_OIDC/writer_implies_read1832=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1833=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1834=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1835=== CONT TestProxyWriteTimeout/narinfo1836=== CONT TestProxyWriteTimeout/unknown_size1837=== CONT TestProxyWriteTimeout/10_GiB_nar1838=== CONT TestProxyWriteTimeout/1_GiB_nar1839--- PASS: TestProxyWriteTimeout (0.13s)1840 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1841 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1842 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1843 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1844=== CONT TestIsValidUploadKey/narinfo1845=== CONT TestIsValidUploadKey/realisation_plus_in_output1846=== CONT TestIsValidUploadKey/unknown_type18472026/09/21 18:17:14 OK 1_commit_pending_closure.sql (4.47ms)1848=== CONT TestIsValidUploadKey/empty_key1849=== CONT TestIsValidUploadKey/absolute1850=== CONT TestIsValidUploadKey/traversal_nar1851=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1852=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1853=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1854=== CONT TestIsValidUploadKey/index.html1855=== CONT TestIsValidUploadKey/nix-cache-info1856=== CONT TestIsValidUploadKey/nar_plain1857=== CONT TestIsValidUploadKey/build_log1858=== CONT TestIsValidUploadKey/listing1859=== CONT TestIsValidUploadKey/nar_xz1860--- PASS: TestClientSharedPathCommittedMidPush (0.90s)1861=== CONT TestIsValidUploadKey/traversal1862=== CONT TestIsValidUploadKey/realisation1863=== CONT TestIsValidUploadKey/build_log_question_mark1864=== CONT TestIsValidUploadKey/build_log_equals1865=== CONT TestIsValidUploadKey/build_log_home-manager_file1866=== CONT TestIsValidUploadKey/build_log_plus_in_name1867=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18682026/09/21 18:17:14 OK 20251218171726_add_pins.sql (4.16ms)1869=== CONT TestIsValidUploadKey/nar_zst18702026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/1871--- PASS: TestIsValidUploadKey (0.13s)1872 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1873 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1874 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1875 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1876 --- PASS: TestIsValidUploadKey/absolute (0.00s)1877 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1878 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1879 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1880 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1881 --- PASS: TestIsValidUploadKey/index.html (0.00s)1882 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1883 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1884 --- PASS: TestIsValidUploadKey/build_log (0.00s)1885 --- PASS: TestIsValidUploadKey/listing (0.00s)1886 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1887 --- PASS: TestIsValidUploadKey/traversal (0.00s)1888 --- PASS: TestIsValidUploadKey/realisation (0.00s)1889 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1890 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1891 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1892 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1893 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1894=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18952026/09/21 18:17:14 INFO Received uploads request method=POST path=/18962026/09/21 18:17:14 OK 2_object_stats_trigger.sql (2.17ms)18972026-09-21 18:17:14.788 UTC [1530] ERROR: relation "goose_db_version" does not exist at character 3618982026-09-21 18:17:14.788 UTC [1530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18992026/09/21 18:17:14 goose: up to current file version: 219002026/09/21 18:17:14 INFO Completed upload id=319012026/09/21 18:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19022026/09/21 18:17:14 INFO Completed upload id=119032026/09/21 18:17:14 INFO Upload complete. (152ms)1904=== NAME TestClientMultipleUploads1905 client_integration_test.go:369: Uploaded 3 paths in 186.470998ms19062026-09-21 18:17:14.792 UTC [1531] ERROR: relation "goose_db_version" does not exist at character 3619072026-09-21 18:17:14.792 UTC [1531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19082026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)1909--- PASS: TestService_ReadAuthMiddleware (0.48s)1910=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19112026/09/21 18:17:14 INFO Received request for more parts method=POST path=/19122026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.35ms)19132026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.56ms)19142026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000019152026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.69ms)1916--- PASS: TestClientMultipleUploads (0.85s)19172026/09/21 18:17:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures1918=== CONT TestResolveDBConnectionString/flag_wins1919=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1920=== CONT TestResolveDBConnectionString/nothing_configured1921=== CONT TestResolveDBConnectionString/missing_file_is_an_error19222026-09-21 18:17:14.806 UTC [1550] ERROR: relation "goose_db_version" does not exist at character 3619232026-09-21 18:17:14.806 UTC [1550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19242026/09/21 18:17:14 INFO Garbage collection started1925=== CONT TestResolveDBConnectionString/file_when_flag_empty1926=== CONT TestCacheConfigHandler/full_config,_no_issuer1927=== CONT TestCacheConfigHandler/no_signing_keys1928=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1929=== CONT TestCacheConfigHandler/no_cache_url_configured1930--- PASS: TestCacheConfigHandler (0.00s)1931 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1932 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1933 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1934 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1935=== CONT TestParseSingleRange/none1936=== CONT TestParseSingleRange/start_past_EOF1937=== CONT TestParseSingleRange/single_byte1938=== CONT TestParseSingleRange/suffix_exceeds_size1939=== CONT TestParseSingleRange/suffix1940=== CONT TestParseSingleRange/end_clamped_to_size1941=== CONT TestParseSingleRange/open-ended1942=== CONT TestParseSingleRange/closed1943=== CONT TestParseSingleRange/malformed_end_before_start1944=== CONT TestParseSingleRange/malformed_both_empty1945=== CONT TestParseSingleRange/malformed_no_dash1946=== CONT TestParseSingleRange/multi-range_ignored1947=== CONT TestParseSingleRange/unknown_unit1948=== CONT TestParseSingleRange/start_far_past_EOF1949--- PASS: TestParseSingleRange (0.00s)1950 --- PASS: TestParseSingleRange/none (0.00s)1951 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1952 --- PASS: TestParseSingleRange/single_byte (0.00s)1953 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1954 --- PASS: TestParseSingleRange/suffix (0.00s)1955 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1956 --- PASS: TestParseSingleRange/open-ended (0.00s)1957 --- PASS: TestParseSingleRange/closed (0.00s)1958 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1959 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1960 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1961 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1962 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1963 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1964=== CONT TestIsValidCachePath/narinfo1965=== CONT TestIsValidCachePath/index.html1966=== CONT TestIsValidCachePath/short_hash1967=== CONT TestIsValidCachePath/wrong_extension1968=== CONT TestIsValidCachePath/invalid_char_e1969=== CONT TestIsValidCachePath/traversal_in_middle1970=== CONT TestIsValidCachePath/invalid_char_u1971=== CONT TestIsValidCachePath/traversal_parent1972=== CONT TestIsValidCachePath/leading_slash1973--- PASS: TestResolveDBConnectionString (0.00s)1974 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1975 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1976 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1977 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1978 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1979=== CONT TestIsValidCachePath/empty1980=== CONT TestIsValidCachePath/nar_uncompressed1981=== CONT TestIsValidCachePath/nix-cache-info1982=== CONT TestIsValidCachePath/realisation1983=== CONT TestIsValidCachePath/random_path1984=== CONT TestIsValidCachePath/ls1985=== CONT TestIsValidCachePath/log1986=== CONT TestIsValidCachePath/nar_xz1987=== CONT TestIsValidCachePath/nar_zst1988=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1989=== CONT TestIsValidCachePath/nar_bz21990--- PASS: TestIsValidCachePath (0.00s)1991 --- PASS: TestIsValidCachePath/narinfo (0.00s)1992 --- PASS: TestIsValidCachePath/index.html (0.00s)1993 --- PASS: TestIsValidCachePath/short_hash (0.00s)1994 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1995 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1996 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1997 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1998 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1999 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2000 --- PASS: TestIsValidCachePath/empty (0.00s)2001 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2002 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2003 --- PASS: TestIsValidCachePath/realisation (0.00s)2004 --- PASS: TestIsValidCachePath/random_path (0.00s)2005 --- PASS: TestIsValidCachePath/ls (0.00s)2006 --- PASS: TestIsValidCachePath/log (0.00s)2007 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2008 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2009 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2010 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2011=== CONT TestService_RequireScope_OIDC/builder_may_write2012=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2013=== CONT TestService_RequireScope_OIDC/writer_implies_read2014=== CONT TestService_RequireScope_OIDC/reader_may_read2015=== CONT TestService_RequireScope_OIDC/static_token_may_write2016=== CONT TestService_RequireScope_OIDC/static_token_may_admin2017=== CONT TestService_RequireScope_OIDC/reader_may_not_write2018=== CONT TestService_RequireScope_OIDC/ops_may_not_write20192026/09/21 18:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2020=== CONT TestService_RequireScope_OIDC/ops_may_admin2021=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2022--- PASS: TestService_RequireScope_OIDC (0.50s)2023 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2024 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2025 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2026 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2027 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20332026/09/21 18:17:14 OK 2_object_stats_trigger.sql (9.42ms)20342026/09/21 18:17:14 goose: up to current file version: 220352026/09/21 18:17:14 OK 20241026095416_initial_model.sql (15.51ms)20362026/09/21 18:17:14 OK 20241026095416_initial_model.sql (19.5ms)20372026/09/21 18:17:14 INFO Aborted multipart uploads count=020382026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)20392026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)20402026/09/21 18:17:14 WARN Force mode enabled - objects will be deleted immediately without grace period20412026/09/21 18:17:14 OK 20251218171726_add_pins.sql (3.64ms)2042=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2043=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2044=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2045=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2046=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2047=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2048=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2049=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2050=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2051=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20522026/09/21 18:17:14 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]2053=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2054=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20552026/09/21 18:17:14 OK 20251218171726_add_pins.sql (4.93ms)20562026/09/21 18:17:14 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/present20572026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)20582026/09/21 18:17:14 OK 20241026095416_initial_model.sql (8.81ms)20592026-09-21 18:17:14.823 UTC [1569] ERROR: relation "goose_db_version" does not exist at character 3620602026-09-21 18:17:14.823 UTC [1569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20612026/09/21 18:17:14 WARN Authentication failed token_preview=eyJhbGciOi...-DRDREuhOw token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2062--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2063 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2064 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2065 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2066 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20672026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)20682026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)20692026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.89ms)20702026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.8ms)20712026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.1ms)20722026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000020732026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.93ms)20742026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (2.18ms)20752026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000020762026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.4ms)20772026-09-21 18:17:14.832 UTC [1570] ERROR: relation "goose_db_version" does not exist at character 3620782026-09-21 18:17:14.832 UTC [1570] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20792026/09/21 18:17:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjNjMTA5NTUtZGQ3ZC00NDQ1LThlNTItN2JiN2YxZmRjZDI3LjFjOTQ2MGM2LTFjOGItNDA4Yi1iZDEzLTczNWRmMmM2ZmMyOXgxNzkwMDE0NjM0MjQzOTc5NzY3 parts=1220802026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)20812026/09/21 18:17:14 OK 2_object_stats_trigger.sql (1.87ms)20822026/09/21 18:17:14 goose: up to current file version: 220832026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.84ms)2084--- PASS: TestRedundantMultipartUpload (1.26s)20852026/09/21 18:17:14 OK 20260905000000_add_claims.sql (3.02ms)20862026/09/21 18:17:14 OK 2_object_stats_trigger.sql (2.11ms)20872026/09/21 18:17:14 goose: up to current file version: 220882026/09/21 18:17:14 OK 20241026095416_initial_model.sql (7.84ms)20892026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (1.82ms)20902026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000020912026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)20922026/09/21 18:17:14 OK 1_commit_pending_closure.sql (2.15ms)20932026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.34ms)20942026/09/21 18:17:14 OK 2_object_stats_trigger.sql (895.2µs)20952026/09/21 18:17:14 goose: up to current file version: 220962026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (2.42ms)20972026/09/21 18:17:14 OK 20241026095416_initial_model.sql (7.86ms)20982026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.38ms)20992026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (905.95µs)21002026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (1.51ms)21012026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000021022026/09/21 18:17:14 OK 20251218171726_add_pins.sql (1.95ms)21032026/09/21 18:17:14 OK 1_commit_pending_closure.sql (1.41ms)21042026/09/21 18:17:14 OK 2_object_stats_trigger.sql (623.45µs)21052026/09/21 18:17:14 goose: up to current file version: 221062026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (2.1ms)21072026-09-21 18:17:14.851 UTC [1574] ERROR: relation "goose_db_version" does not exist at character 3621082026-09-21 18:17:14.851 UTC [1574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21092026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.65ms)21102026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (1.51ms)21112026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000021122026/09/21 18:17:14 OK 1_commit_pending_closure.sql (1.31ms)21132026/09/21 18:17:14 OK 2_object_stats_trigger.sql (638.25µs)21142026/09/21 18:17:14 goose: up to current file version: 221152026/09/21 18:17:14 OK 20241026095416_initial_model.sql (7.09ms)21162026/09/21 18:17:14 OK 20251210153512_drop_unused_gin_index.sql (988.9µs)21172026/09/21 18:17:14 OK 20251218171726_add_pins.sql (2.43ms)21182026/09/21 18:17:14 OK 20260628120000_add_object_size_and_stats.sql (2.26ms)21192026/09/21 18:17:14 OK 20260905000000_add_claims.sql (2.78ms)21202026/09/21 18:17:14 OK 20260920000000_drop_claims.sql (1.46ms)21212026/09/21 18:17:14 goose: successfully migrated database to version: 2026092000000021222026/09/21 18:17:14 OK 1_commit_pending_closure.sql (1.58ms)21232026/09/21 18:17:14 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21242026/09/21 18:17:14 WARN mTLS auth: bound subjects configured but subject DN unavailable21252026/09/21 18:17:14 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2126--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.40s)21272026/09/21 18:17:14 OK 2_object_stats_trigger.sql (660.91µs)21282026/09/21 18:17:14 goose: up to current file version: 22129--- PASS: TestCacheStatsHandler (0.42s)21302026/09/21 18:17:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.306682ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2131--- PASS: TestService_ReadScope_PublicByDefault (0.39s)2132=== NAME TestClientCADerivations2133 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2328076899/001/store/0ql8f54yyhcjw5w49pnjpch8irn6lwg4-ca-test2134 client_ca_test.go:139: Found 1 dependencies (including self)2135--- PASS: TestResurrectedObjectNotDeleted (0.42s)2136--- PASS: TestReadProxyNarinfo (0.38s)21372026/09/21 18:17:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2138--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.37s)21392026/09/21 18:17:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21402026/09/21 18:17:15 WARN Refused reserved pin name=worker-x86_64-linux21412026/09/21 18:17:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21422026/09/21 18:17:15 INFO Received create pin request method=POST path=/api/pins/my-app21432026/09/21 18:17:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2144--- PASS: TestCreatePin_ReservedPins (0.40s)21452026/09/21 18:17:15 INFO Received uploads request method=POST path=/api/pending_closures21462026/09/21 18:17:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21472026/09/21 18:17:15 INFO Uploading 0ql8f54yyhcjw5w49pnjpch8irn6lwg4-ca-test (144B)21482026/09/21 18:17:15 WARN Failed to register uploaded object key=log/h6vj7k7ac9pi6a9i8b92ws5xzff99rdj-ca-test.drv error="server returned 404: 404 page not found\n"21492026/09/21 18:17:15 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21502026/09/21 18:17:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21512026/09/21 18:17:15 WARN Failed to register uploaded object key=0ql8f54yyhcjw5w49pnjpch8irn6lwg4.ls error="server returned 404: 404 page not found\n"21522026/09/21 18:17:15 INFO Signed narinfos id=1 count=121532026/09/21 18:17:15 INFO Uploading 1 narinfos2154--- PASS: TestObjectStatsTrigger (0.40s)21552026/09/21 18:17:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21562026/09/21 18:17:15 WARN Failed to register uploaded object key=0ql8f54yyhcjw5w49pnjpch8irn6lwg4.narinfo error="server returned 404: 404 page not found\n"21572026/09/21 18:17:15 INFO Completed upload id=121582026/09/21 18:17:15 INFO Upload complete. (101ms)2159=== NAME TestClientCADerivations2160 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2328076899/001/store/0ql8f54yyhcjw5w49pnjpch8irn6lwg4-ca-test2161 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2162 Compression: zstd2163 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2164 NarSize: 1442165 References: 2166 Deriver: /build/TestClientCADerivations2328076899/001/store/h6vj7k7ac9pi6a9i8b92ws5xzff99rdj-ca-test.drv2167 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2168 client_ca_test.go:185: Checking for realisation files in S3...21692026/09/21 18:17:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.188292ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2170 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2171 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2172--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.40s)21732026/09/21 18:17:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21742026/09/21 18:17:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2175=== NAME TestClientCADerivations2176 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2177 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2178 error: binary cache 's3://bucket44?endpoint=http://localhost:37513®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2328076899/001/store'2179 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12180--- PASS: TestClientCADerivations (0.88s)2181=== NAME TestOrphanedObjectsGC2182 orphaned_objects_gc_test.go:290: GC Test Summary:2183 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2184 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2185 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2186 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2187 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2188--- PASS: TestOrphanedObjectsGC (0.67s)21892026/09/21 18:17:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2190--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)2191 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2192 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2193 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.76s)21942026/09/21 18:17:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.966514ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21952026/09/21 18:17:15 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=021962026/09/21 18:17:15 INFO Vacuumed table table=pending_closures21972026/09/21 18:17:15 INFO Vacuumed table table=pending_objects21982026/09/21 18:17:15 INFO Vacuumed table table=multipart_uploads21992026/09/21 18:17:15 INFO Vacuumed table table=closures22002026/09/21 18:17:15 INFO Vacuumed table table=objects22012026/09/21 18:17:15 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=022022026/09/21 18:17:15 INFO Vacuumed table table=pending_closures22032026/09/21 18:17:15 INFO Vacuumed table table=pending_objects22042026/09/21 18:17:15 INFO Vacuumed table table=multipart_uploads22052026/09/21 18:17:15 INFO Vacuumed table table=closures22062026/09/21 18:17:15 INFO Vacuumed table table=objects22072026/09/21 18:17:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.623073823s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2208=== NAME TestOrphanedObjectsGCStressTest2209 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2210 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22112026/09/21 18:17:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02212=== NAME TestPinProtectsFromGC2213 client_integration_test.go:794: Pin successfully protected closure from garbage collection2214--- PASS: TestPinProtectsFromGC (2.97s)22152026/09/21 18:17:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02216=== NAME TestClientIntegration2217 client_integration_test.go:323: Objects in database after GC:2218 client_integration_test.go:323: Successfully deleted all objects with GC --force2219=== NAME TestOrphanedObjectsGCStressTest2220 orphaned_objects_gc_test.go:509: Stress test completed successfully:2221 orphaned_objects_gc_test.go:510: - Active objects preserved: 202222 orphaned_objects_gc_test.go:511: - Objects deleted: 2102223 orphaned_objects_gc_test.go:512: - Total GC'd: 2102224--- PASS: TestOrphanedObjectsGCStressTest (2.22s)2225--- PASS: TestClientIntegration (2.86s)22262026/09/21 18:17:17 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-config22272026/09/21 18:17:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.727326ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22282026/09/21 18:17:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.889781ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22292026/09/21 18:17:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=799.602339ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/09/21 18:17:18 WARN Rate limiter enabled after throttle name=s3-test rate=522312026/09/21 18:17:18 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2232=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2233 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102234 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002235--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.50s)22362026/09/21 18:17:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.450006001s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22372026/09/21 18:17:20 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"22382026/09/21 18:17:20 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_closures22392026/09/21 18:17:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.160329ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22402026/09/21 18:17:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.693567ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22412026/09/21 18:17:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=771.448134ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22422026/09/21 18:17:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.456631333s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2243--- PASS: TestClientErrorHandling (0.13s)2244 --- PASS: TestClientErrorHandling/InvalidStorePath (0.44s)2245 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.54s)2246 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.13s)2247PASS2248{"timestamp":"2026-09-21T18:17:23.880630588Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46834","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(393)"}22492026-09-21 18:17:24.122 UTC [129] LOG: received smart shutdown request22502026-09-21 18:17:24.126 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122512026-09-21 18:17:24.136 UTC [134] LOG: shutting down22522026-09-21 18:17:24.136 UTC [134] LOG: checkpoint starting: shutdown immediate22532026-09-21 18:17:25.370 UTC [134] LOG: checkpoint complete: wrote 11205 buffers (68.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.258 s, sync=0.945 s, total=1.235 s; sync files=19072, longest=0.069 s, average=0.001 s; distance=260289 kB, estimate=260289 kB; lsn=0/11596248, redo lsn=0/1159624822542026-09-21 18:17:25.446 UTC [129] LOG: database system is shut down2255Running OIDC tests...2256=== RUN TestGlobMatch2257=== PAUSE TestGlobMatch2258=== RUN TestAudienceForIssuer2259=== PAUSE TestAudienceForIssuer2260=== RUN TestValidateToken_ValidToken2261=== PAUSE TestValidateToken_ValidToken2262=== RUN TestValidateToken_WrongAudience2263=== PAUSE TestValidateToken_WrongAudience2264=== RUN TestValidateToken_Expired2265=== PAUSE TestValidateToken_Expired2266=== RUN TestValidateToken_BoundClaimsMismatch2267=== PAUSE TestValidateToken_BoundClaimsMismatch2268=== RUN TestValidateToken_BoundSubjectMismatch2269=== PAUSE TestValidateToken_BoundSubjectMismatch2270=== RUN TestValidateToken_MultipleProviders2271=== PAUSE TestValidateToken_MultipleProviders2272=== RUN TestValidateToken_NoMatchingProvider2273=== PAUSE TestValidateToken_NoMatchingProvider2274=== RUN TestValidateToken_KubernetesServiceAccount2275=== PAUSE TestValidateToken_KubernetesServiceAccount2276=== RUN TestNewValidator_KubernetesRequiresCA2277=== PAUSE TestNewValidator_KubernetesRequiresCA2278=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2279=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2280=== RUN TestPins_ReservedForMatchingRule2281=== PAUSE TestPins_ReservedForMatchingRule2282=== RUN TestPins_TopLevelShorthand2283=== PAUSE TestPins_TopLevelShorthand2284=== RUN TestPins_ConfigValidation2285=== PAUSE TestPins_ConfigValidation2286=== RUN TestScopes_LegacyProviderDefaultsToWrite2287=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2288=== RUN TestScopes_Rules2289=== PAUSE TestScopes_Rules2290=== RUN TestScopes_ConfigValidation2291=== PAUSE TestScopes_ConfigValidation2292=== CONT TestGlobMatch2293=== CONT TestValidateToken_BoundClaimsMismatch2294=== CONT TestPins_ReservedForMatchingRule2295=== RUN TestGlobMatch/foo_foo2296=== PAUSE TestGlobMatch/foo_foo2297=== RUN TestGlobMatch/foo_bar2298=== PAUSE TestGlobMatch/foo_bar2299=== CONT TestValidateToken_Expired2300=== CONT TestValidateToken_WrongAudience2301=== CONT TestValidateToken_ValidToken2302=== CONT TestAudienceForIssuer2303=== CONT TestValidateToken_MultipleProviders2304=== CONT TestValidateToken_NoMatchingProvider2305=== CONT TestPins_ConfigValidation2306=== CONT TestScopes_ConfigValidation2307=== CONT TestScopes_Rules2308=== CONT TestScopes_LegacyProviderDefaultsToWrite2309=== CONT TestValidateToken_BoundSubjectMismatch2310=== CONT TestPins_TopLevelShorthand2311=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2312=== CONT TestNewValidator_KubernetesRequiresCA2313=== CONT TestValidateToken_KubernetesServiceAccount2314=== RUN TestGlobMatch/*_2315=== PAUSE TestGlobMatch/*_2316=== RUN TestGlobMatch/*_anything2317=== PAUSE TestGlobMatch/*_anything2318=== RUN TestGlobMatch/foo*_foo2319=== PAUSE TestGlobMatch/foo*_foo2320=== RUN TestGlobMatch/foo*_foobar2321=== PAUSE TestGlobMatch/foo*_foobar2322=== RUN TestGlobMatch/foo*_bar2323=== PAUSE TestGlobMatch/foo*_bar2324=== RUN TestGlobMatch/*bar_bar2325--- PASS: TestAudienceForIssuer (0.00s)2326=== PAUSE TestGlobMatch/*bar_bar2327=== RUN TestGlobMatch/*bar_foobar2328--- PASS: TestScopes_ConfigValidation (0.00s)2329=== PAUSE TestGlobMatch/*bar_foobar2330=== RUN TestGlobMatch/*bar_foo23312026/09/21 18:17:27 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232332=== PAUSE TestGlobMatch/*bar_foo2333--- PASS: TestPins_ConfigValidation (0.01s)23342026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45701/oidc2335=== RUN TestGlobMatch/foo*bar_foobar23362026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38683/oidc23372026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33329/oidc23382026/09/21 18:17:27 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39297/oidc23392026/09/21 18:17:27 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43967/oidc23402026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33001/oidc2341=== PAUSE TestGlobMatch/foo*bar_foobar23422026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33721/oidc23432026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44807/oidc2344=== RUN TestGlobMatch/foo*bar_foo123bar23452026/09/21 18:17:27 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33257/oidc2346=== PAUSE TestGlobMatch/foo*bar_foo123bar23472026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40873/oidc2348=== RUN TestGlobMatch/foo*bar_foobarbaz23492026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34753/oidc23502026/09/21 18:17:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35877/oidc2351=== PAUSE TestGlobMatch/foo*bar_foobarbaz2352=== RUN TestGlobMatch/*/*_foo/bar2353=== PAUSE TestGlobMatch/*/*_foo/bar2354=== RUN TestGlobMatch/*/*_foo2355=== PAUSE TestGlobMatch/*/*_foo2356=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2357=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2358=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02359=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02360=== RUN TestGlobMatch/refs/*/main_refs/heads/main2361=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2362=== RUN TestGlobMatch/fo?_foo2363=== PAUSE TestGlobMatch/fo?_foo2364=== RUN TestGlobMatch/fo?_fo2365=== PAUSE TestGlobMatch/fo?_fo2366=== RUN TestGlobMatch/fo?_fooo2367=== PAUSE TestGlobMatch/fo?_fooo2368=== RUN TestGlobMatch/?oo_foo2369=== PAUSE TestGlobMatch/?oo_foo2370=== RUN TestGlobMatch/?oo_boo2371=== PAUSE TestGlobMatch/?oo_boo2372=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2373=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2374=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2375=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2376=== CONT TestGlobMatch/foo_foo2377=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/foo*bar_foobarbaz2379=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2380=== CONT TestGlobMatch/foo_bar2381=== CONT TestGlobMatch/foo*_bar2382=== CONT TestGlobMatch/foo*_foo2383=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2384=== CONT TestGlobMatch/foo*_foobar2385=== CONT TestGlobMatch/*bar_foo2386=== CONT TestGlobMatch/fo?_fooo2387=== CONT TestGlobMatch/?oo_boo2388=== CONT TestGlobMatch/foo*bar_foo123bar2389--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2390=== CONT TestGlobMatch/*/*_foo/bar2391=== CONT TestGlobMatch/*bar_bar2392=== CONT TestGlobMatch/foo*bar_foobar2393=== CONT TestGlobMatch/*_2394=== CONT TestGlobMatch/*_anything2395=== CONT TestGlobMatch/*bar_foobar2396=== CONT TestGlobMatch/refs/*/main_refs/heads/main2397=== CONT TestGlobMatch/*/*_foo2398=== CONT TestGlobMatch/?oo_foo2399=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02400=== CONT TestGlobMatch/fo?_fo2401=== CONT TestGlobMatch/fo?_foo2402--- PASS: TestPins_TopLevelShorthand (0.02s)2403--- PASS: TestValidateToken_ValidToken (0.02s)2404--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2405--- PASS: TestGlobMatch (0.02s)2406 --- PASS: TestGlobMatch/foo_foo (0.00s)2407 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2409 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/foo_bar (0.00s)2411 --- PASS: TestGlobMatch/foo*_bar (0.00s)2412 --- PASS: TestGlobMatch/foo*_foo (0.00s)2413 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2414 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foo (0.00s)2416 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2417 --- PASS: TestGlobMatch/?oo_boo (0.00s)2418 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2419 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2420 --- PASS: TestGlobMatch/*bar_bar (0.00s)2421 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2422 --- PASS: TestGlobMatch/*_ (0.00s)2423 --- PASS: TestGlobMatch/*_anything (0.00s)2424 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2425 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2426 --- PASS: TestGlobMatch/*/*_foo (0.00s)2427 --- PASS: TestGlobMatch/?oo_foo (0.00s)2428 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2429 --- PASS: TestGlobMatch/fo?_fo (0.00s)2430 --- PASS: TestGlobMatch/fo?_foo (0.00s)2431--- PASS: TestValidateToken_Expired (0.02s)2432--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2433--- PASS: TestValidateToken_WrongAudience (0.02s)24342026/09/21 18:17:27 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:425772435--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2436--- PASS: TestPins_ReservedForMatchingRule (0.02s)2437--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2438--- PASS: TestValidateToken_MultipleProviders (0.02s)2439--- PASS: TestScopes_Rules (0.02s)2440--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)24412026/09/21 18:17:27 http: TLS handshake error from 127.0.0.1:34476: remote error: tls: bad certificate2442--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2443PASS2444Running hook tests...2445=== RUN TestSendPathsEmpty2446=== PAUSE TestSendPathsEmpty2447=== RUN TestQueueEnqueueAndFetch2448=== PAUSE TestQueueEnqueueAndFetch2449=== RUN TestQueueDeduplication2450=== PAUSE TestQueueDeduplication2451=== RUN TestQueueRemove2452=== PAUSE TestQueueRemove2453=== RUN TestQueueFetchBatchLimit2454=== PAUSE TestQueueFetchBatchLimit2455=== RUN TestQueueRetryMovesToBack2456=== PAUSE TestQueueRetryMovesToBack2457=== RUN TestQueueFetchRemoveLifecycle2458=== PAUSE TestQueueFetchRemoveLifecycle2459=== RUN TestQueueConcurrentWriters2460=== PAUSE TestQueueConcurrentWriters2461=== RUN TestQueueRemoveLargeClosure2462=== PAUSE TestQueueRemoveLargeClosure2463=== RUN TestServerClientIntegration2464=== PAUSE TestServerClientIntegration2465=== RUN TestServerQueueError2466=== PAUSE TestServerQueueError2467=== RUN TestGetListenerSocketActivation2468 server_test.go:210: === RUN TestGetListenerSocketActivation2469 --- PASS: TestGetListenerSocketActivation (0.00s)2470 PASS2471 2472--- PASS: TestGetListenerSocketActivation (0.01s)2473=== RUN TestDrainIsolatesPoisonPath2474=== PAUSE TestDrainIsolatesPoisonPath2475=== RUN TestRunNotBlockedByPoisonHead2476=== PAUSE TestRunNotBlockedByPoisonHead2477=== RUN TestDrainGivesUpWhenServerDown2478=== PAUSE TestDrainGivesUpWhenServerDown2479=== RUN TestFailedPathPrunedByLaterClosure2480=== PAUSE TestFailedPathPrunedByLaterClosure2481=== RUN TestWorkerUploadsAndRemoves2482=== PAUSE TestWorkerUploadsAndRemoves2483=== RUN TestWorkerSkipsGCdPaths2484=== PAUSE TestWorkerSkipsGCdPaths2485=== RUN TestWorkerPrunesClosureDeps2486=== PAUSE TestWorkerPrunesClosureDeps2487=== RUN TestDrainTimeout2488=== PAUSE TestDrainTimeout2489=== CONT TestSendPathsEmpty2490=== CONT TestServerQueueError2491--- PASS: TestSendPathsEmpty (0.00s)2492=== CONT TestServerClientIntegration2493=== CONT TestQueueRemoveLargeClosure2494=== CONT TestQueueConcurrentWriters2495=== CONT TestQueueFetchRemoveLifecycle2496=== CONT TestQueueRetryMovesToBack2497=== CONT TestQueueFetchBatchLimit2498=== CONT TestQueueRemove2499=== CONT TestQueueDeduplication25002026/09/21 18:17:27 ERROR Failed to queue paths error="permission denied" count=12501=== CONT TestQueueEnqueueAndFetch2502--- PASS: TestServerClientIntegration (0.00s)2503=== CONT TestWorkerPrunesClosureDeps2504=== CONT TestDrainTimeout2505=== CONT TestDrainGivesUpWhenServerDown2506=== CONT TestWorkerUploadsAndRemoves2507=== CONT TestFailedPathPrunedByLaterClosure2508=== CONT TestWorkerSkipsGCdPaths2509=== CONT TestRunNotBlockedByPoisonHead2510=== CONT TestDrainIsolatesPoisonPath2511--- PASS: TestServerQueueError (0.00s)25122026/09/21 18:17:27 INFO Uploading batch count=225132026/09/21 18:17:27 INFO Uploading batch count=125142026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=125152026/09/21 18:17:27 INFO Upload queue status pending=325162026/09/21 18:17:27 INFO Upload queue status pending=225172026/09/21 18:17:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths91939720/002/nonexistent25182026/09/21 18:17:27 INFO Uploading batch count=42519--- PASS: TestQueueRemove (0.02s)25202026/09/21 18:17:27 INFO Upload queue status pending=22521--- PASS: TestQueueEnqueueAndFetch (0.02s)25222026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=425232026/09/21 18:17:27 INFO Upload queue status pending=225242026/09/21 18:17:27 INFO Uploading batch count=125252026/09/21 18:17:27 INFO Uploading batch count=125262026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=125272026/09/21 18:17:27 INFO Uploading batch count=225282026/09/21 18:17:27 INFO Uploading batch count=12529--- PASS: TestQueueFetchBatchLimit (0.02s)25302026/09/21 18:17:27 INFO Uploading batch count=125312026/09/21 18:17:27 INFO Uploading batch count=225322026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=22533--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25342026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2716181411/002/a25352026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1312824729/002/bbb2536--- PASS: TestQueueDeduplication (0.02s)2537--- PASS: TestQueueRetryMovesToBack (0.02s)25382026/09/21 18:17:27 INFO Uploading batch count=125392026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2716181411/002/b25402026/09/21 18:17:27 INFO Uploading batch count=225412026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=225422026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2716181411/002/c25432026/09/21 18:17:27 INFO Uploading batch count=125442026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2716181411/002/d25452026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=125462026/09/21 18:17:27 INFO Uploading batch count=225472026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=225482026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2716181411/002/e2549--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25502026/09/21 18:17:27 INFO Uploading batch count=125512026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=125522026/09/21 18:17:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2716181411/002/f25532026/09/21 18:17:27 INFO Uploading batch count=125542026/09/21 18:17:27 ERROR Upload failed error="upload failed" count=125552026/09/21 18:17:27 ERROR Drain finished with paths left in queue remaining=1025562026/09/21 18:17:27 ERROR Drain finished with paths left in queue remaining=12557--- PASS: TestDrainIsolatesPoisonPath (0.02s)2558--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2559--- PASS: TestWorkerPrunesClosureDeps (0.04s)2560--- PASS: TestWorkerSkipsGCdPaths (0.04s)2561--- PASS: TestWorkerUploadsAndRemoves (0.04s)2562--- PASS: TestQueueRemoveLargeClosure (0.09s)25632026/09/21 18:17:27 ERROR Upload failed error="context deadline exceeded" count=225642026/09/21 18:17:27 ERROR Drain finished with paths left in queue remaining=42565--- PASS: TestDrainTimeout (0.22s)2566--- PASS: TestQueueConcurrentWriters (0.28s)25672026/09/21 18:17:28 INFO Uploading batch count=125682026/09/21 18:17:28 INFO Uploading batch count=125692026/09/21 18:17:28 INFO Uploading batch count=125702026/09/21 18:17:28 ERROR Upload failed error="upload failed" count=125712026/09/21 18:17:28 INFO Uploading batch count=125722026/09/21 18:17:28 ERROR Upload failed error="upload failed" count=125732026/09/21 18:17:28 INFO Uploading batch count=125742026/09/21 18:17:28 ERROR Upload failed error="upload failed" count=125752026/09/21 18:17:28 INFO Uploading batch count=125762026/09/21 18:17:28 ERROR Upload failed error="upload failed" count=125772026/09/21 18:17:28 ERROR Drain finished with paths left in queue remaining=12578--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2579PASS