niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #333
· 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.03s)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 TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97=== CONT TestEncodeNixBase32WithRealHash98=== CONT TestSetClientTLSDoesNotMutateDefaultTransport99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestResolveStorePath101=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess102=== CONT TestRateLimiterFeedback103=== RUN TestRateLimiterFeedback/429_enables_limiter104=== PAUSE TestRateLimiterFeedback/429_enables_limiter105=== CONT TestPathInfoCACompatibility106=== CONT TestStreamPushReportsSignatures107=== CONT TestParsePathInfoJSONMultiplePaths108=== CONT TestParsePathInfoJSON109=== CONT TestPathInfoHashCompatibility110=== CONT TestGetStorePathHash1112026/10/01 10:11:38 WARN Rate limiter enabled after throttle name=server-test rate=5112=== CONT TestConvertHashToNix32113=== CONT TestScriptTokenCachesUntilRefresh114=== CONT TestScriptTokenEmptyCommand115=== RUN TestParsePathInfoJSON/Nix_format116=== CONT TestScriptTokenScriptFails117=== CONT TestScriptTokenBadJSON118=== CONT TestScriptTokenEmptyToken119=== CONT TestFileTokenMissing120=== CONT TestScriptTokenNoExpiryRerunsEveryCall121=== CONT TestFileTokenEmpty122=== CONT TestSetClientTLSErrors1232026/10/01 10:11:38 ERROR Upload failed error=boom count=1124=== CONT TestFileTokenReadsAndCaches125=== CONT TestStaticToken126--- PASS: TestShellSplit (0.00s)127--- PASS: TestEncodeNixBase32WithRealHash (0.00s)128--- PASS: TestResolveStorePath (0.00s)129=== CONT TestStreamPushRequestLine130=== RUN TestRateLimiterFeedback/503_enables_limiter131=== RUN TestPathInfoCACompatibility/null_ca_field132=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths133=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)134=== RUN TestGetStorePathHash/valid_store_path135=== RUN TestConvertHashToNix32/SRI_format_to_Nix32136=== PAUSE TestParsePathInfoJSON/Nix_format137=== CONT TestStreamPushBatchesUnderLoad138=== CONT TestStreamPushGivesUpOnDeadServer139=== CONT TestStreamPushReportsEveryPath140=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141--- PASS: TestScriptTokenEmptyCommand (0.00s)142--- PASS: TestStreamPushReportsSignatures (0.00s)143=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix321442026/10/01 10:11:38 WARN Rate limiter enabled after throttle name=server-test rate=5145=== RUN TestParsePathInfoJSON/Lix_format1462026/10/01 10:11:38 ERROR Upload failed error="connection refused" count=20147=== PAUSE TestParsePathInfoJSON/Lix_format148=== CONT TestDumpPathWriterError1492026/10/01 10:11:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33681150=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1512026/10/01 10:11:38 ERROR Upload failed error=boom count=1152=== RUN TestConvertHashToNix32/already_Nix32_format1532026/10/01 10:11:38 ERROR Server seems unavailable, giving up on batch untried=17154=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestRateLimiterFeedback/503_enables_limiter157=== PAUSE TestGetStorePathHash/valid_store_path158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon161--- PASS: TestStaticToken (0.00s)162--- PASS: TestScriptTokenScriptFails (0.01s)163--- PASS: TestFileTokenMissing (0.01s)164--- PASS: TestFileTokenReadsAndCaches (0.01s)165--- PASS: TestDoServerRequestAttachesToken (0.02s)166=== CONT TestStreamPushIsolatesFailures167=== CONT TestDumpPathMatchesNix168=== CONT TestShellSplitErrors169=== RUN TestGetStorePathHash/basename_without_hyphen_should_error170=== CONT TestUploadMultipart_PartsInParallel1712026/10/01 10:11:38 ERROR Upload failed error="bad path" count=3172=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1732026/10/01 10:11:38 WARN Rate limiter backed off name=server-test rate=5174=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI175=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121772026/10/01 10:11:38 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33681178=== CONT TestRegisterUploadedObjectReusesConnections179=== RUN TestParsePathInfoJSON/empty_input180=== CONT TestDumpPathSingleFile181=== RUN TestSetClientTLSErrors/missing_cert_file182=== PAUSE TestConvertHashToNix32/already_Nix32_format183=== CONT TestEncodeNixBase32184=== CONT TestCaseHackSuffix185=== PAUSE TestSetClientTLSErrors/missing_cert_file186=== RUN TestSetClientTLSErrors/missing_key_file187--- PASS: TestFileTokenEmpty (0.01s)188--- PASS: TestStreamPushReportsEveryPath (0.00s)189--- PASS: TestScriptTokenEmptyToken (0.01s)190=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter191=== CONT TestUploadMultipart_SupersededByPeer192=== CONT TestFilterOversizedClosures193=== RUN TestPathInfoCACompatibility/old_string_format_-_text194=== CONT TestSetClientTLS195=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error196=== CONT TestPartSizeForNAR197=== CONT TestClientSignaturesByStorePath198=== RUN TestConvertHashToNix32/invalid_format199=== PAUSE TestParsePathInfoJSON/empty_input200=== RUN TestEncodeNixBase32/test_string_hash201=== PAUSE TestSetClientTLSErrors/missing_key_file202--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)203--- PASS: TestScriptTokenBadJSON (0.01s)204--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)205=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths206=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text207=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI208=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512209=== RUN TestSetClientTLSErrors/missing_ca_file210=== PAUSE TestConvertHashToNix32/invalid_format211=== CONT TestConvertHashToNix32/SRI_format_to_Nix32212=== CONT TestConvertHashToNix32/invalid_format213=== CONT TestConvertHashToNix32/already_Nix32_format214=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)215=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error216=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error217=== RUN TestParsePathInfoJSON/whitespace_only218=== RUN TestFilterOversizedClosures/no_limit_keeps_everything219=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter220=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter221=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter222=== CONT TestRateLimiterFeedback/429_enables_limiter223=== CONT TestRateLimiterFeedback/503_enables_limiter224=== PAUSE TestEncodeNixBase32/test_string_hash225=== RUN TestEncodeNixBase32/empty_input226=== PAUSE TestEncodeNixBase32/empty_input227=== CONT TestEncodeNixBase32/test_string_hash228=== CONT TestEncodeNixBase32/empty_input229=== RUN TestUploadMultipart_SupersededByPeer/exists230=== PAUSE TestUploadMultipart_SupersededByPeer/exists231=== RUN TestUploadMultipart_SupersededByPeer/missing232=== PAUSE TestUploadMultipart_SupersededByPeer/missing233=== CONT TestUploadMultipart_SupersededByPeer/exists234=== CONT TestUploadMultipart_SupersededByPeer/missing235--- PASS: TestShellSplitErrors (0.00s)236--- PASS: TestStreamPushIsolatesFailures (0.00s)237=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive238=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive239=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon240=== PAUSE TestSetClientTLSErrors/missing_ca_file241=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths242=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error243=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error244=== CONT TestGetStorePathHash/valid_store_path245=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error246=== PAUSE TestParsePathInfoJSON/whitespace_only247=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error248=== CONT TestGetStorePathHash/basename_without_hyphen_should_error249=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything250=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter251=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter252=== RUN TestSetClientTLSErrors/invalid_ca_file253=== RUN TestPathInfoCACompatibility/new_structured_format_-_text254=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text2552026/10/01 10:11:38 WARN Rate limiter enabled after throttle name=server-test rate=5256=== RUN TestSetClientTLS/rejects_connection_without_client_cert2572026/10/01 10:11:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39471258=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert259=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2602026/10/01 10:11:38 WARN Rate limiter backed off name=server-test rate=5261=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA2622026/10/01 10:11:38 WARN Rate limiter enabled after throttle name=server-test rate=5263=== PAUSE TestSetClientTLSErrors/invalid_ca_file2642026/10/01 10:11:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33231265=== CONT TestSetClientTLSErrors/missing_cert_file266=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method267=== CONT TestSetClientTLSErrors/missing_ca_file2682026/10/01 10:11:38 WARN Rate limiter backed off name=server-test rate=5269=== RUN TestPartSizeForNAR/zero_stays_at_minimum270=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum271--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)272--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)273=== RUN TestParsePathInfoJSON/invalid_JSON274=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped275=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped276=== RUN TestFilterOversizedClosures/all_closures_skipped277=== PAUSE TestFilterOversizedClosures/all_closures_skipped278=== RUN TestSetClientTLS/preserves_debug_logging_transport279=== PAUSE TestSetClientTLS/preserves_debug_logging_transport280=== CONT TestSetClientTLSErrors/invalid_ca_file281=== CONT TestSetClientTLSErrors/missing_key_file282=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method283=== CONT TestPathInfoCACompatibility/null_ca_field284=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method285=== CONT TestPathInfoCACompatibility/new_structured_format_-_text286--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)287--- PASS: TestClientSignaturesByStorePath (0.00s)288=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive289--- PASS: TestConvertHashToNix32 (0.04s)290 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)291 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)292 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)293=== PAUSE TestParsePathInfoJSON/invalid_JSON294--- PASS: TestEncodeNixBase32 (0.03s)295 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)296 --- PASS: TestEncodeNixBase32/empty_input (0.00s)297--- PASS: TestPathInfoHashCompatibility (0.01s)298 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)299 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)300 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)301 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)302=== CONT TestParsePathInfoJSON/Nix_format303--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)304 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)305 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)306=== CONT TestFilterOversizedClosures/all_closures_skipped307--- PASS: TestRateLimiterFeedback (0.05s)308 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)309 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)310 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)311 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)312--- PASS: TestGetStorePathHash (0.04s)313 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)314 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)315 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)316 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)3172026/10/01 10:11:38 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=50318--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)319 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)320 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)321=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3222026/10/01 10:11:38 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=2000323=== CONT TestSetClientTLS/rejects_connection_without_client_cert324=== CONT TestSetClientTLS/preserves_debug_logging_transport325=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA326=== RUN TestPartSizeForNAR/small_stays_at_minimum327=== CONT TestPathInfoCACompatibility/old_string_format_-_text328=== CONT TestFilterOversizedClosures/no_limit_keeps_everything329=== CONT TestParsePathInfoJSON/invalid_JSON330=== CONT TestParsePathInfoJSON/empty_input331=== CONT TestParsePathInfoJSON/whitespace_only332=== CONT TestParsePathInfoJSON/Lix_format333--- PASS: TestSetClientTLSErrors (0.04s)334 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)337 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)338--- PASS: TestPathInfoCACompatibility (0.05s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)341 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)342 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)343 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)344=== PAUSE TestPartSizeForNAR/small_stays_at_minimum345=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum346=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum347=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts348=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts349=== RUN TestPartSizeForNAR/1_TiB350=== PAUSE TestPartSizeForNAR/1_TiB351=== RUN TestPartSizeForNAR/5_TiB_S3_max_object352=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object353=== RUN TestPartSizeForNAR/capped_at_5_GiB354=== PAUSE TestPartSizeForNAR/capped_at_5_GiB355=== CONT TestPartSizeForNAR/zero_stays_at_minimum356--- PASS: TestFilterOversizedClosures (0.01s)357 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)358 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)359 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)360=== CONT TestPartSizeForNAR/capped_at_5_GiB361=== CONT TestPartSizeForNAR/5_TiB_S3_max_object362=== CONT TestPartSizeForNAR/1_TiB363=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum364=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts365=== CONT TestPartSizeForNAR/small_stays_at_minimum366--- PASS: TestParsePathInfoJSON (0.05s)367 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)368 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)369 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)370 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)371 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)372--- PASS: TestPartSizeForNAR (0.01s)373 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)375 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380--- PASS: TestStreamPushRequestLine (0.06s)3812026/10/01 10:11:38 http: TLS handshake error from 127.0.0.1:58420: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)387--- PASS: TestCaseHackSuffix (0.06s)388--- PASS: TestDumpPathSingleFile (0.06s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1462334764/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1462334764/data -l logfile start422423/build/postgres1462334764:5432 - no response4242026-10-01 10:11:40.321 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:11:40.322 UTC [129] LOG: listening on Unix socket "/build/postgres1462334764/.s.PGSQL.5432"4262026-10-01 10:11:40.328 UTC [136] LOG: database system was shut down at 2026-10-01 10:11:39 UTC4272026-10-01 10:11:40.333 UTC [129] LOG: database system is ready to accept connections428/build/postgres1462334764:5432 - accepting connections429{"timestamp":"2026-10-01T10:11:40.629061429Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3056415d-ce67-45db-80a0-115e14275c8e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(393)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 10:11:40.816 UTC [565] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 10:11:40.816 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 10:11:40 OK 20241026095416_initial_model.sql (9.39ms)4762026/10/01 10:11:40 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)4772026/10/01 10:11:40 OK 20251218171726_add_pins.sql (2.76ms)4782026/10/01 10:11:40 OK 20260628120000_add_object_size_and_stats.sql (2.39ms)4792026/10/01 10:11:40 OK 20260905000000_add_claims.sql (3.15ms)4802026/10/01 10:11:40 OK 20260920000000_drop_claims.sql (1.62ms)4812026/10/01 10:11:40 OK 20260923120000_add_pushes.sql (1.09ms)4822026/10/01 10:11:40 goose: successfully migrated database to version: 202609231200004832026/10/01 10:11:40 OK 1_commit_pending_closure.sql (1.42ms)4842026/10/01 10:11:40 OK 2_object_stats_trigger.sql (688.71µs)4852026/10/01 10:11:40 OK 3_commit_push.sql (667.71µs)4862026/10/01 10:11:40 goose: up to current file version: 34872026/10/01 10:11:40 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 10:11:41 INFO lead: released remote=192.0.2.1:12344892026/10/01 10:11:41 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 10:11:41 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 10:11:41.590 UTC [575] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 10:11:41.590 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 10:11:41 OK 20241026095416_initial_model.sql (6.11ms)4982026/10/01 10:11:41 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)4992026/10/01 10:11:41 OK 20251218171726_add_pins.sql (2ms)5002026/10/01 10:11:41 OK 20260628120000_add_object_size_and_stats.sql (2.06ms)5012026/10/01 10:11:41 OK 20260905000000_add_claims.sql (1.95ms)5022026/10/01 10:11:41 OK 20260920000000_drop_claims.sql (1.35ms)5032026/10/01 10:11:41 OK 20260923120000_add_pushes.sql (985.87µs)5042026/10/01 10:11:41 goose: successfully migrated database to version: 202609231200005052026/10/01 10:11:41 OK 1_commit_pending_closure.sql (1.53ms)5062026/10/01 10:11:41 OK 2_object_stats_trigger.sql (702.11µs)5072026/10/01 10:11:41 OK 3_commit_push.sql (614.94µs)5082026/10/01 10:11:41 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCEndsOnShutdown543=== PAUSE TestGCEndsOnShutdown544=== RUN TestGCTaskStore_StartNew545=== PAUSE TestGCTaskStore_StartNew546=== RUN TestGCTaskStore_DeduplicateSameParams547=== PAUSE TestGCTaskStore_DeduplicateSameParams548=== RUN TestGCTaskStore_ConflictDifferentParams549=== PAUSE TestGCTaskStore_ConflictDifferentParams550=== RUN TestGCTaskStore_GetEmpty551=== PAUSE TestGCTaskStore_GetEmpty552=== RUN TestGCTaskStore_GetReturnsLatest553=== PAUSE TestGCTaskStore_GetReturnsLatest554=== RUN TestGCTaskStore_CompletedAllowsNewTask555=== PAUSE TestGCTaskStore_CompletedAllowsNewTask556=== RUN TestGCTaskStore_PhaseUpdates557=== PAUSE TestGCTaskStore_PhaseUpdates558=== RUN TestGCTaskStore_Fail559=== PAUSE TestGCTaskStore_Fail560=== RUN TestGracefulShutdownDrainsInflight561=== PAUSE TestGracefulShutdownDrainsInflight562=== RUN TestService_healthCheckHandler563=== PAUSE TestService_healthCheckHandler564=== RUN TestService_readinessHandler565=== PAUSE TestService_readinessHandler566=== RUN TestGenerateLandingPage567=== PAUSE TestGenerateLandingPage568=== RUN TestCacheConfigHandlerMaxNarSize569=== PAUSE TestCacheConfigHandlerMaxNarSize570=== RUN TestCreatePendingClosureRejectsOversizedNAR571=== PAUSE TestCreatePendingClosureRejectsOversizedNAR572=== RUN TestNARDeduplicationMetadataUploadBug573=== PAUSE TestNARDeduplicationMetadataUploadBug574=== RUN TestMetricsInventory575=== PAUSE TestMetricsInventory576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestOrphanedObjectsGC589=== PAUSE TestOrphanedObjectsGC590=== RUN TestOrphanedObjectsGCStressTest591=== PAUSE TestOrphanedObjectsGCStressTest592=== RUN TestCreatePin_ReservedPins593=== PAUSE TestCreatePin_ReservedPins594=== RUN TestPresentReportsOnlyClosureRoots595=== PAUSE TestPresentReportsOnlyClosureRoots596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 10:11:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestIsValidUploadKey675=== PAUSE TestIsValidUploadKey676=== RUN TestUploadHandlersRejectInvalidKeys677=== PAUSE TestUploadHandlersRejectInvalidKeys678=== RUN TestUploadHandlersRejectOversizedBody679=== PAUSE TestUploadHandlersRejectOversizedBody680=== RUN TestService_cleanupPendingClosuresHandler681=== PAUSE TestService_cleanupPendingClosuresHandler682=== RUN TestService_createPendingClosureHandler683=== PAUSE TestService_createPendingClosureHandler684=== RUN TestService_verifyS3Integrity685=== PAUSE TestService_verifyS3Integrity686=== RUN TestCompleteMultipartUnregistered687=== PAUSE TestCompleteMultipartUnregistered688=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT689=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT690=== CONT TestService_AuthMiddleware691=== CONT TestIsValidUploadKey692=== RUN TestIsValidUploadKey/narinfo693=== PAUSE TestIsValidUploadKey/narinfo694=== RUN TestIsValidUploadKey/nar_zst695=== PAUSE TestIsValidUploadKey/nar_zst696=== RUN TestIsValidUploadKey/nar_xz697=== PAUSE TestIsValidUploadKey/nar_xz698=== RUN TestIsValidUploadKey/nar_plain699=== PAUSE TestIsValidUploadKey/nar_plain700=== RUN TestIsValidUploadKey/listing701=== PAUSE TestIsValidUploadKey/listing702=== RUN TestIsValidUploadKey/build_log703=== PAUSE TestIsValidUploadKey/build_log704=== CONT TestGCSweepSkipsPendingObjects705=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT706=== CONT TestCompleteMultipartUnregistered707=== CONT TestService_verifyS3Integrity708=== CONT TestService_createPendingClosureHandler709=== CONT TestService_cleanupPendingClosuresHandler710=== CONT TestUploadHandlersRejectOversizedBody711=== CONT TestUploadHandlersRejectInvalidKeys712=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info713=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info714=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal715=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal716=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key717=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key718=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key719=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key720=== CONT TestCacheConfigHandlerMaxNarSize721=== CONT TestGCEndsOnShutdown722--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)723=== CONT TestService_readinessHandler724=== CONT TestService_healthCheckHandler725=== CONT TestGracefulShutdownDrainsInflight726=== CONT TestGCTaskStore_Fail727--- PASS: TestGCTaskStore_Fail (0.00s)728=== CONT TestGCTaskStore_PhaseUpdates729=== CONT TestGCTaskStore_CompletedAllowsNewTask730=== CONT TestGCTaskStore_GetReturnsLatest731=== CONT TestGCTaskStore_GetEmpty732=== CONT TestGCTaskStore_ConflictDifferentParams733=== CONT TestGCTaskStore_DeduplicateSameParams734=== CONT TestGCTaskStore_StartNew735=== CONT TestCreatePendingClosureRejectsOversizedNAR736=== RUN TestIsValidUploadKey/build_log_home-manager_file737=== CONT TestCommitRacingPendingCleanupKeepsObjects738=== CONT TestGenerateLandingPage7392026/10/01 10:11:41 INFO Starting HTTP server address=127.0.0.1:44079740=== CONT TestPushWaitsForSweepHoldingRow741--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)742--- PASS: TestGCTaskStore_GetEmpty (0.00s)743--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)744--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)745=== CONT TestSweepRechecksPendingAfterLocking746=== CONT TestRegisterCompletedObjectNeedsPendingRow747=== CONT TestGetExistingObjectsLocksRows748=== CONT TestSweepSkipsRowsLockedByPush749--- PASS: TestGCTaskStore_StartNew (0.00s)7502026-10-01 10:11:42.022 UTC [620] ERROR: relation "goose_db_version" does not exist at character 367512026-10-01 10:11:42.022 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC752=== CONT TestFailedS3DeleteKeepsTombstone753--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)754=== PAUSE TestIsValidUploadKey/build_log_home-manager_file755=== RUN TestIsValidUploadKey/build_log_plus_in_name756=== PAUSE TestIsValidUploadKey/build_log_plus_in_name7572026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures758=== RUN TestIsValidUploadKey/build_log_question_mark759=== PAUSE TestIsValidUploadKey/build_log_question_mark7602026/10/01 10:11:42 INFO Shutdown signal received, draining in-flight requests timeout=10s761=== RUN TestIsValidUploadKey/build_log_equals762=== PAUSE TestIsValidUploadKey/build_log_equals763=== CONT TestForceGCDuringPushOffersSweptObject764--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)765--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)766=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection767=== CONT TestGCSweepDeliversEachKeyOnce768=== RUN TestIsValidUploadKey/realisation769=== PAUSE TestIsValidUploadKey/realisation770=== RUN TestIsValidUploadKey/realisation_plus_in_output771=== PAUSE TestIsValidUploadKey/realisation_plus_in_output772=== RUN TestIsValidUploadKey/nix-cache-info773=== PAUSE TestIsValidUploadKey/nix-cache-info774=== RUN TestIsValidUploadKey/index.html775=== PAUSE TestIsValidUploadKey/index.html776=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows777=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows778=== RUN TestIsValidUploadKey/narinfo_key,_nar_type779=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type780=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check781=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check782=== RUN TestIsValidUploadKey/nar_key,_narinfo_type783=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type784=== RUN TestIsValidUploadKey/listing_key,_narinfo_type785=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type786=== RUN TestIsValidUploadKey/traversal787=== PAUSE TestIsValidUploadKey/traversal788=== RUN TestIsValidUploadKey/traversal_nar789=== PAUSE TestIsValidUploadKey/traversal_nar790=== RUN TestIsValidUploadKey/absolute791=== PAUSE TestIsValidUploadKey/absolute792=== RUN TestIsValidUploadKey/empty_key793=== PAUSE TestIsValidUploadKey/empty_key794=== RUN TestIsValidUploadKey/unknown_type795=== PAUSE TestIsValidUploadKey/unknown_type796=== CONT TestTombstonedObjectOfferedWithoutWaiting797=== CONT TestClientWithDependencies798--- PASS: TestGenerateLandingPage (0.01s)799=== CONT TestDeduplicatedObjectsRecordedAsPending8002026/10/01 10:11:42 OK 20241026095416_initial_model.sql (28.19ms)801=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure802=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure803=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart804=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart805=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts806=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts807=== CONT TestPushDedupSurvivesConcurrentGC8082026-10-01 10:11:42.150 UTC [638] ERROR: relation "goose_db_version" does not exist at character 368092026-10-01 10:11:42.150 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.76ms)8112026-10-01 10:11:42.157 UTC [644] ERROR: relation "goose_db_version" does not exist at character 368122026-10-01 10:11:42.157 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026-10-01 10:11:42.157 UTC [645] ERROR: relation "goose_db_version" does not exist at character 368142026-10-01 10:11:42.157 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026-10-01 10:11:42.158 UTC [646] ERROR: relation "goose_db_version" does not exist at character 368162026-10-01 10:11:42.158 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8172026-10-01 10:11:42.163 UTC [648] ERROR: relation "goose_db_version" does not exist at character 368182026-10-01 10:11:42.163 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026/10/01 10:11:42 OK 20251218171726_add_pins.sql (20.53ms)820--- PASS: TestGracefulShutdownDrainsInflight (0.29s)821=== CONT TestGCMetrics8222026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (9.1ms)8232026/10/01 10:11:42 OK 20241026095416_initial_model.sql (16.85ms)8242026/10/01 10:11:42 OK 20260905000000_add_claims.sql (8.96ms)8252026/10/01 10:11:42 OK 20241026095416_initial_model.sql (25.93ms)8262026/10/01 10:11:42 OK 20241026095416_initial_model.sql (16.52ms)8272026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)8282026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)8292026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)8302026/10/01 10:11:42 OK 20241026095416_initial_model.sql (17.26ms)8312026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (6.21ms)8322026/10/01 10:11:42 OK 20251218171726_add_pins.sql (4.48ms)8332026-10-01 10:11:42.204 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368342026-10-01 10:11:42.204 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)8362026/10/01 10:11:42 OK 20251218171726_add_pins.sql (5.32ms)8372026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.65ms)8382026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200008392026-10-01 10:11:42.208 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368402026-10-01 10:11:42.208 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8412026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)8422026/10/01 10:11:42 OK 20251218171726_add_pins.sql (7.81ms)8432026/10/01 10:11:42 OK 20241026095416_initial_model.sql (24.62ms)8442026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)8452026/10/01 10:11:42 OK 20251218171726_add_pins.sql (6.28ms)8462026/10/01 10:11:42 OK 20260905000000_add_claims.sql (4.12ms)8472026/10/01 10:11:42 OK 1_commit_pending_closure.sql (5.47ms)8482026-10-01 10:11:42.214 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368492026-10-01 10:11:42.214 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (4.17ms)8512026-10-01 10:11:42.216 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368522026-10-01 10:11:42.216 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8532026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (15.07ms)8542026/10/01 10:11:42 OK 2_object_stats_trigger.sql (18.76ms)8552026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (23.34ms)8562026/10/01 10:11:42 OK 20260905000000_add_claims.sql (20.66ms)8572026/10/01 10:11:42 OK 20251218171726_add_pins.sql (17.72ms)8582026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (20.57ms)8592026/10/01 10:11:42 OK 3_commit_push.sql (3.01ms)8602026/10/01 10:11:42 goose: up to current file version: 38612026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (8.89ms)8622026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200008632026/10/01 10:11:42 OK 20241026095416_initial_model.sql (25.38ms)8642026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (7.35ms)8652026/10/01 10:11:42 OK 20260905000000_add_claims.sql (7.5ms)8662026/10/01 10:11:42 OK 1_commit_pending_closure.sql (4.4ms)8672026/10/01 10:11:42 OK 20260905000000_add_claims.sql (9.89ms)8682026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (11.2ms)8692026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (4.22ms)8702026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (4.01ms)8712026-10-01 10:11:42.245 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368722026-10-01 10:11:42.245 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8732026/10/01 10:11:42 OK 2_object_stats_trigger.sql (3.4ms)8742026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (5.74ms)8752026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200008762026-10-01 10:11:42.248 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368772026-10-01 10:11:42.248 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8782026-10-01 10:11:42.249 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368792026-10-01 10:11:42.249 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8802026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (6.5ms)8812026/10/01 10:11:42 OK 3_commit_push.sql (3.59ms)8822026/10/01 10:11:42 goose: up to current file version: 38832026/10/01 10:11:42 OK 20241026095416_initial_model.sql (16.44ms)8842026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (4.73ms)8852026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200008862026/10/01 10:11:42 OK 20241026095416_initial_model.sql (16.46ms)8872026/10/01 10:11:42 OK 1_commit_pending_closure.sql (5.35ms)8882026/10/01 10:11:42 OK 20241026095416_initial_model.sql (23.35ms)8892026-10-01 10:11:42.252 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368902026-10-01 10:11:42.252 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026/10/01 10:11:42 OK 20260905000000_add_claims.sql (9.08ms)8922026/10/01 10:11:42 OK 20251218171726_add_pins.sql (9.01ms)8932026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)8942026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.53ms)8952026/10/01 10:11:42 OK 2_object_stats_trigger.sql (3.27ms)8962026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)8972026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (5.7ms)8982026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200008992026/10/01 10:11:42 OK 1_commit_pending_closure.sql (4.75ms)9002026/10/01 10:11:42 OK 3_commit_push.sql (3.25ms)9012026/10/01 10:11:42 goose: up to current file version: 39022026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.78ms)9032026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (6.3ms)9042026/10/01 10:11:42 OK 20251218171726_add_pins.sql (6.21ms)9052026/10/01 10:11:42 OK 20251218171726_add_pins.sql (6.14ms)9062026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (6.37ms)9072026-10-01 10:11:42.261 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369082026-10-01 10:11:42.261 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026/10/01 10:11:42 OK 3_commit_push.sql (2.29ms)9102026/10/01 10:11:42 goose: up to current file version: 39112026/10/01 10:11:42 OK 1_commit_pending_closure.sql (5.89ms)9122026/10/01 10:11:42 OK 20251218171726_add_pins.sql (6.11ms)9132026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.68ms)9142026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200009152026/10/01 10:11:42 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"916--- PASS: TestService_AuthMiddleware (0.39s)917=== CONT TestGCBugBareHashReferences9182026/10/01 10:11:42 OK 20260905000000_add_claims.sql (4.58ms)9192026/10/01 10:11:42 OK 2_object_stats_trigger.sql (3.3ms)9202026-10-01 10:11:42.266 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369212026-10-01 10:11:42.266 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (14.39ms)9232026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (14.49ms)9242026/10/01 10:11:42 OK 3_commit_push.sql (13.81ms)9252026/10/01 10:11:42 goose: up to current file version: 39262026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (17.24ms)9272026/10/01 10:11:42 OK 20241026095416_initial_model.sql (20.54ms)9282026/10/01 10:11:42 OK 1_commit_pending_closure.sql (15.12ms)9292026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (14.47ms)9302026/10/01 10:11:42 OK 20241026095416_initial_model.sql (21.29ms)9312026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.99ms)9322026/10/01 10:11:42 INFO Received cleanup request method=DELETE path=/api/pending_closures9332026/10/01 10:11:42 OK 2_object_stats_trigger.sql (4.99ms)9342026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (4.11ms)9352026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (6ms)9362026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200009372026/10/01 10:11:42 OK 20260905000000_add_claims.sql (11.09ms)9382026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=09392026/10/01 10:11:42 OK 20260905000000_add_claims.sql (12.41ms)9402026/10/01 10:11:42 OK 3_commit_push.sql (2.68ms)9412026/10/01 10:11:42 goose: up to current file version: 39422026/10/01 10:11:42 OK 20241026095416_initial_model.sql (24.41ms)9432026-10-01 10:11:42.289 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369442026-10-01 10:11:42.289 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9452026/10/01 10:11:42 OK 20241026095416_initial_model.sql (25.88ms)9462026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures9472026-10-01 10:11:42.292 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369482026-10-01 10:11:42.292 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9492026/10/01 10:11:42 OK 20260905000000_add_claims.sql (12.81ms)9502026/10/01 10:11:42 OK 20251218171726_add_pins.sql (8.63ms)9512026/10/01 10:11:42 OK 20251218171726_add_pins.sql (7.45ms)9522026/10/01 10:11:42 OK 1_commit_pending_closure.sql (6.19ms)9532026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (6.77ms)9542026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (5.69ms)9552026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)9562026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)9572026/10/01 10:11:42 OK 20241026095416_initial_model.sql (15.03ms)9582026/10/01 10:11:42 OK 2_object_stats_trigger.sql (3.82ms)9592026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (5.18ms)9602026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (4.64ms)9612026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200009622026/10/01 10:11:42 OK 20241026095416_initial_model.sql (17.77ms)9632026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (5.1ms)9642026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200009652026/10/01 10:11:42 OK 3_commit_push.sql (2.35ms)9662026/10/01 10:11:42 goose: up to current file version: 39672026/10/01 10:11:42 OK 20251218171726_add_pins.sql (5.55ms)9682026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)9692026/10/01 10:11:42 OK 20251218171726_add_pins.sql (5.63ms)9702026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (6.76ms)9712026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (6.9ms)9722026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)9732026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.1ms)9742026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.59ms)9752026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200009762026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.81ms)9772026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.74ms)9782026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.15ms)9792026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.72ms)9802026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.12ms)9812026/10/01 10:11:42 OK 20251218171726_add_pins.sql (5.5ms)9822026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.7ms)9832026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)9842026/10/01 10:11:42 OK 20251218171726_add_pins.sql (4.69ms)9852026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (6.35ms)9862026/10/01 10:11:42 OK 3_commit_push.sql (2.33ms)9872026/10/01 10:11:42 goose: up to current file version: 39882026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.79ms)9892026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.18ms)9902026/10/01 10:11:42 INFO Received cleanup request method=DELETE path=/api/pending_closures9912026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.37ms)9922026-10-01 10:11:42.308 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369932026-10-01 10:11:42.308 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9942026/10/01 10:11:42 OK 3_commit_push.sql (2.99ms)9952026/10/01 10:11:42 goose: up to current file version: 39962026-10-01 10:11:42.309 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369972026-10-01 10:11:42.309 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026/10/01 10:11:42 OK 20241026095416_initial_model.sql (11.87ms)9992026-10-01 10:11:42.309 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3610002026-10-01 10:11:42.309 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10012026-10-01 10:11:42.310 UTC [669] ERROR: relation "goose_db_version" does not exist at character 3610022026-10-01 10:11:42.310 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10032026/10/01 10:11:42 INFO Aborted multipart uploads count=1 kept=010042026/10/01 10:11:42 OK 3_commit_push.sql (2.69ms)10052026/10/01 10:11:42 goose: up to current file version: 310062026/10/01 10:11:42 OK 20260905000000_add_claims.sql (4.07ms)10072026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)10082026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.39ms)10092026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010102026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.3ms)10112026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010122026/10/01 10:11:42 OK 20260905000000_add_claims.sql (4.69ms)10132026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)10142026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)10152026/10/01 10:11:42 OK 20241026095416_initial_model.sql (11.31ms)10162026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.04ms)10202026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.22ms)10212026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.95ms)10222026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.1ms)10232026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)10242026/10/01 10:11:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10252026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.4ms)10262026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.14ms)10272026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.28ms)10282026-10-01 10:11:42.315 UTC [645] ERROR: Closure does not exist: id=110292026-10-01 10:11:42.315 UTC [645] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE10302026-10-01 10:11:42.315 UTC [645] STATEMENT: -- name: CommitPendingClosure :exec1031 SELECT commit_pending_closure($1::bigint)1032 1033--- PASS: TestService_cleanupPendingClosuresHandler (0.43s)10342026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.31ms)1035=== CONT TestLeadEndsOnShutdown10362026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.93ms)10372026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.23ms)10382026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010392026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.75ms)10402026/10/01 10:11:42 OK 3_commit_push.sql (1.36ms)10412026/10/01 10:11:42 goose: up to current file version: 310422026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.16ms)10432026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010442026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.25ms)10452026/10/01 10:11:42 OK 3_commit_push.sql (1.3ms)10462026/10/01 10:11:42 goose: up to current file version: 310472026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.58ms)10482026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)10492026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.77ms)10502026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.37ms)10512026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010522026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.5ms)10532026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010542026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.23ms)10552026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.96ms)10562026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.62ms)10572026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.74ms)10582026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.82ms)10592026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.7ms)10602026/10/01 10:11:42 OK 3_commit_push.sql (1.87ms)10612026/10/01 10:11:42 goose: up to current file version: 310622026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.78ms)10632026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.74ms)10642026/10/01 10:11:42 OK 3_commit_push.sql (2.01ms)10652026/10/01 10:11:42 goose: up to current file version: 310662026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.54ms)10672026-10-01 10:11:42.325 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3610682026-10-01 10:11:42.325 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10692026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.83ms)10702026/10/01 10:11:42 OK 20241026095416_initial_model.sql (10.2ms)10712026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.35ms)10722026/10/01 10:11:42 OK 3_commit_push.sql (1.87ms)10732026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.54ms)10742026/10/01 10:11:42 goose: up to current file version: 310752026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.49ms)10762026/10/01 10:11:42 OK 3_commit_push.sql (715.82µs)10772026/10/01 10:11:42 goose: up to current file version: 310782026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.92ms)10792026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)10802026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.97ms)10812026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010822026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)10832026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)10842026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)10852026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (1.89ms)10862026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.78ms)10872026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.72ms)10882026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000010892026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.22ms)10902026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.93ms)10912026-10-01 10:11:42.331 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3610922026-10-01 10:11:42.331 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.76ms)10942026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.98ms)10952026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.92ms)10962026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.5ms)10972026/10/01 10:11:42 OK 3_commit_push.sql (2.43ms)10982026/10/01 10:11:42 goose: up to current file version: 310992026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.73ms)11002026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)11012026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)11022026/10/01 10:11:42 OK 3_commit_push.sql (2.48ms)11032026/10/01 10:11:42 goose: up to current file version: 311042026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.78ms)11052026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)11062026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.6ms)11072026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.71ms)11082026/10/01 10:11:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11092026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.58ms)11102026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.77ms)11112026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.77ms)11122026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.35ms)11132026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)11142026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.44ms)11152026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.33ms)11162026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.21ms)11172026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.88ms)11182026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011192026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.54ms)11202026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011212026/10/01 10:11:42 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1122--- PASS: TestCompleteMultipartUnregistered (0.47s)1123=== CONT TestLeadElectsOneAndHandsOver11242026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.79ms)11252026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.24ms)11262026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011272026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.31ms)11282026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011292026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.31ms)11302026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.15ms)11312026/10/01 10:11:42 OK 20241026095416_initial_model.sql (10.97ms)11322026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.07ms)11332026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.2ms)11342026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.62ms)11352026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)11362026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.74ms)11372026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)11382026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.16ms)11392026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.3ms)11402026/10/01 10:11:42 OK 3_commit_push.sql (1.59ms)11412026/10/01 10:11:42 goose: up to current file version: 311422026/10/01 10:11:42 OK 3_commit_push.sql (1.37ms)11432026/10/01 10:11:42 goose: up to current file version: 311442026/10/01 10:11:42 OK 3_commit_push.sql (1.64ms)11452026/10/01 10:11:42 goose: up to current file version: 311462026/10/01 10:11:42 OK 3_commit_push.sql (1.47ms)11472026/10/01 10:11:42 goose: up to current file version: 311482026/10/01 10:11:42 OK 20260905000000_add_claims.sql (10.27ms)11492026/10/01 10:11:42 OK 20251218171726_add_pins.sql (10.44ms)11502026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.21ms)11512026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)11522026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.96ms)11532026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011542026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.22ms)11552026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.36ms)11562026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (1.71ms)11572026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.07ms)11582026/10/01 10:11:42 OK 3_commit_push.sql (1.22ms)11592026/10/01 10:11:42 goose: up to current file version: 311602026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.09ms)11612026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011622026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures11632026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.43ms)11642026-10-01 10:11:42.378 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3611652026-10-01 10:11:42.378 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.47ms)11672026/10/01 10:11:42 OK 3_commit_push.sql (1.61ms)11682026/10/01 10:11:42 goose: up to current file version: 311692026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.74ms)11702026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)11712026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=011722026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.8ms)11742026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period11752026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (2.91ms)11762026/10/01 10:11:42 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=011772026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.64ms)11782026/10/01 10:11:42 INFO Vacuumed table table=pending_closures11792026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (1.85ms)11802026/10/01 10:11:42 INFO Vacuumed table table=pending_objects11812026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.36ms)11822026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000011832026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads11842026/10/01 10:11:42 INFO Vacuumed table table=closures11852026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.02ms)11862026/10/01 10:11:42 INFO Vacuumed table table=objects11872026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.13ms)11882026/10/01 10:11:42 OK 3_commit_push.sql (1.58ms)11892026/10/01 10:11:42 goose: up to current file version: 311902026-10-01 10:11:42.416 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611912026-10-01 10:11:42.416 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1192--- PASS: TestGCSweepSkipsPendingObjects (0.54s)1193=== CONT TestResolveDBConnectionString1194=== RUN TestResolveDBConnectionString/flag_wins1195=== PAUSE TestResolveDBConnectionString/flag_wins1196=== RUN TestResolveDBConnectionString/file_when_flag_empty1197=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1198=== RUN TestResolveDBConnectionString/missing_file_is_an_error1199=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1200=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1201=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1202=== RUN TestResolveDBConnectionString/nothing_configured1203=== PAUSE TestResolveDBConnectionString/nothing_configured1204=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12052026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/01 10:11:42 OK 20241026095416_initial_model.sql (7.99ms)12072026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)12082026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.82ms)1209--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.56s)1210=== CONT TestClientFallsBackToClosures12112026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)12122026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.07ms)12132026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (1.43ms)12142026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.75ms)12152026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000012162026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.53ms)12172026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.49ms)12182026/10/01 10:11:42 OK 3_commit_push.sql (758.13µs)12192026/10/01 10:11:42 goose: up to current file version: 312202026-10-01 10:11:42.454 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3612212026-10-01 10:11:42.454 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12222026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.19ms)12232026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)12242026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3ms)12252026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)1226--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.59s)1227=== CONT TestClientPushesUseOnePush12282026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.72ms)12292026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.18ms)12302026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.65ms)12312026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000012322026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.09ms)12332026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.08ms)12342026/10/01 10:11:42 OK 3_commit_push.sql (1.25ms)12352026/10/01 10:11:42 goose: up to current file version: 312362026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=012372026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period12382026/10/01 10:11:42 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=01239--- PASS: TestService_healthCheckHandler (0.61s)1240=== CONT TestPinProtectsFromGC12412026/10/01 10:11:42 INFO Vacuumed table table=pending_closures12422026/10/01 10:11:42 INFO Vacuumed table table=pending_objects12432026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads12442026/10/01 10:11:42 INFO Vacuumed table table=closures12452026/10/01 10:11:42 INFO Vacuumed table table=objects12462026-10-01 10:11:42.525 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612472026-10-01 10:11:42.525 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1248--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.64s)1249=== CONT TestClientSharedPathCommittedMidPush12502026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures12512026/10/01 10:11:42 OK 20241026095416_initial_model.sql (10.36ms)12522026-10-01 10:11:42.542 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3612532026-10-01 10:11:42.542 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)12552026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.15ms)12562026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)12572026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.58ms)12582026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.95ms)12592026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.72ms)12602026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)12612026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.24ms)12622026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200001263--- PASS: TestGCEndsOnShutdown (0.67s)1264=== CONT TestReadProxyHead12652026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.1ms)12662026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.65ms)12672026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.75ms)12682026/10/01 10:11:42 OK 3_commit_push.sql (1.52ms)12692026/10/01 10:11:42 goose: up to current file version: 312702026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)12712026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.79ms)12722026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.55ms)12732026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.17ms)12742026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000012752026-10-01 10:11:42.579 UTC [700] ERROR: relation "goose_db_version" does not exist at character 3612762026-10-01 10:11:42.579 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.24ms)12782026/10/01 10:11:42 WARN readiness check failed error="closed pool"1279--- PASS: TestService_readinessHandler (0.69s)1280=== CONT TestProxyWriteTimeout1281=== RUN TestProxyWriteTimeout/narinfo1282=== PAUSE TestProxyWriteTimeout/narinfo1283=== RUN TestProxyWriteTimeout/1_GiB_nar1284=== PAUSE TestProxyWriteTimeout/1_GiB_nar1285=== RUN TestProxyWriteTimeout/10_GiB_nar1286=== PAUSE TestProxyWriteTimeout/10_GiB_nar1287=== RUN TestProxyWriteTimeout/unknown_size1288=== PAUSE TestProxyWriteTimeout/unknown_size1289=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12902026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.24ms)12912026/10/01 10:11:42 OK 3_commit_push.sql (1.5ms)12922026/10/01 10:11:42 goose: up to current file version: 312932026/10/01 10:11:42 OK 20241026095416_initial_model.sql (10.2ms)12942026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)12952026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.01ms)12962026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)12972026-10-01 10:11:42.606 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612982026-10-01 10:11:42.606 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12992026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.26ms)13002026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (11.56ms)13012026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.13ms)13022026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000013032026/10/01 10:11:42 OK 1_commit_pending_closure.sql (3.91ms)13042026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.55ms)13052026/10/01 10:11:42 OK 3_commit_push.sql (1.47ms)13062026/10/01 10:11:42 goose: up to current file version: 313072026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.88ms)13082026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)13092026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.89ms)13102026-10-01 10:11:42.636 UTC [705] ERROR: relation "goose_db_version" does not exist at character 3613112026-10-01 10:11:42.636 UTC [705] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13122026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=013132026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)13142026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period13152026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.97ms)13162026/10/01 10:11:42 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=013172026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.65ms)13182026/10/01 10:11:42 INFO Vacuumed table table=pending_closures13192026/10/01 10:11:42 INFO Vacuumed table table=pending_objects13202026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads13212026/10/01 10:11:42 INFO Vacuumed table table=closures13222026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.35ms)13232026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000013242026/10/01 10:11:42 INFO Vacuumed table table=objects13252026/10/01 10:11:42 OK 1_commit_pending_closure.sql (1.94ms)13262026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.97ms)13272026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.02ms)13282026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)13292026/10/01 10:11:42 OK 3_commit_push.sql (1.22ms)13302026/10/01 10:11:42 goose: up to current file version: 313312026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=013322026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=013332026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.57ms)13342026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period13352026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)13372026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.69ms)13382026-10-01 10:11:42.662 UTC [708] ERROR: relation "goose_db_version" does not exist at character 3613392026-10-01 10:11:42.662 UTC [708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (1.59ms)13412026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.83ms)13422026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000013432026/10/01 10:11:42 OK 1_commit_pending_closure.sql (1.48ms)13442026/10/01 10:11:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=013452026/10/01 10:11:42 OK 2_object_stats_trigger.sql (844.95µs)13462026/10/01 10:11:42 INFO Vacuumed table table=pending_closures13472026/10/01 10:11:42 OK 3_commit_push.sql (781.6µs)13482026/10/01 10:11:42 goose: up to current file version: 313492026/10/01 10:11:42 INFO Vacuumed table table=pending_objects13502026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads13512026/10/01 10:11:42 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=013522026/10/01 10:11:42 INFO Vacuumed table table=closures13532026/10/01 10:11:42 INFO Vacuumed table table=objects13542026/10/01 10:11:42 INFO Vacuumed table table=pending_closures1355--- PASS: TestSweepSkipsRowsLockedByPush (0.78s)1356=== CONT TestSkippedUploadsHandler13572026/10/01 10:11:42 INFO Client skipped oversized paths paths=3 nar_bytes=500000000013582026/10/01 10:11:42 OK 20241026095416_initial_model.sql (7.55ms)13592026/10/01 10:11:42 INFO Vacuumed table table=pending_objects13602026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads13612026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (982.75µs)13622026/10/01 10:11:42 INFO Vacuumed table table=closures13632026-10-01 10:11:42.676 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3613642026-10-01 10:11:42.676 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13652026/10/01 10:11:42 INFO Vacuumed table table=objects1366--- PASS: TestGetExistingObjectsLocksRows (0.79s)1367=== CONT TestParseSize13682026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.12ms)1369--- PASS: TestParseSize (0.00s)1370=== CONT TestService_Rustfstest1371--- PASS: TestSweepRechecksPendingAfterLocking (0.79s)1372=== CONT TestPresignedUploadRegisteredBeforeCommit13732026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (2.6ms)1374--- PASS: TestSkippedUploadsHandler (0.01s)13752026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.14ms)1376=== CONT TestCacheConfigHandler1377=== RUN TestCacheConfigHandler/full_config,_no_issuer1378=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1379=== RUN TestCacheConfigHandler/no_cache_url_configured1380=== PAUSE TestCacheConfigHandler/no_cache_url_configured1381=== RUN TestCacheConfigHandler/no_signing_keys1382=== PAUSE TestCacheConfigHandler/no_signing_keys1383=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1384=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1385=== CONT TestCompletedNarNotReofferedAcrossClosures13862026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (1.48ms)13872026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures13882026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (1.47ms)13892026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000013902026/10/01 10:11:42 OK 1_commit_pending_closure.sql (1.81ms)13912026/10/01 10:11:42 OK 20241026095416_initial_model.sql (7.43ms)13922026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.4ms)13932026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)13942026/10/01 10:11:42 OK 3_commit_push.sql (1.02ms)13952026/10/01 10:11:42 goose: up to current file version: 313962026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.47ms)13972026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.91ms)13982026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.63ms)13992026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.67ms)14002026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.22ms)14012026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000014022026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.83ms)14032026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.46ms)14042026/10/01 10:11:42 OK 3_commit_push.sql (1.13ms)14052026/10/01 10:11:42 goose: up to current file version: 314062026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures1407--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.66s)1408=== CONT TestClientMultipleUploads14092026/10/01 10:11:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14102026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=014112026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period14122026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/01 10:11:42 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LjhiN2I4MzY3LTY4NjItNDRmNS1hZWUxLWFkYjU2ZGRjNWExOHgxNzkwODQ5NTAyMzI1MDU1ODc3 parts=1014142026/10/01 10:11:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14152026-10-01 10:11:42.777 UTC [736] ERROR: relation "goose_db_version" does not exist at character 3614162026-10-01 10:11:42.777 UTC [736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14172026-10-01 10:11:42.777 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3614182026-10-01 10:11:42.777 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14192026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=014202026/10/01 10:11:42 INFO Completed upload id=114212026-10-01 10:11:42.783 UTC [739] ERROR: relation "goose_db_version" does not exist at character 3614222026-10-01 10:11:42.783 UTC [739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14232026/10/01 10:11:42 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014242026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period14252026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures14262026/10/01 10:11:42 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14272026/10/01 10:11:42 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1428--- PASS: TestFailedS3DeleteKeepsTombstone (0.72s)1429=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14302026/10/01 10:11:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures14312026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.12ms)14322026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.69ms)14332026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)14342026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)14352026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.95ms)14362026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.49ms)14372026/10/01 10:11:42 OK 20241026095416_initial_model.sql (8.62ms)14382026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=014392026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)14402026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)14412026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)14422026/10/01 10:11:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014432026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures14442026/10/01 10:11:42 INFO Vacuumed table table=pending_closures14452026/10/01 10:11:42 INFO Vacuumed table table=pending_objects14462026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.84ms)14472026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads14482026/10/01 10:11:42 INFO Vacuumed table table=closures14492026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.83ms)14502026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.66ms)14512026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.62ms)14522026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.74ms)14532026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)14542026/10/01 10:11:42 INFO Vacuumed table table=objects14552026/10/01 10:11:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01456--- PASS: TestGCSweepDeliversEachKeyOnce (0.74s)1457=== CONT TestRedundantMultipartUpload14582026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.3ms)14592026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000014602026/10/01 10:11:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14612026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (3.18ms)14622026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000014632026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.73ms)14642026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.1ms)1465--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.74s)1466=== CONT TestClientIntegration14672026/10/01 10:11:42 INFO Vacuumed table table=pending_closures14682026/10/01 10:11:42 OK 1_commit_pending_closure.sql (1.98ms)14692026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.65ms)14702026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.73ms)14712026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.73ms)14722026/10/01 10:11:42 INFO Vacuumed table table=pending_objects14732026/10/01 10:11:42 OK 3_commit_push.sql (1.57ms)14742026/10/01 10:11:42 goose: up to current file version: 314752026/10/01 10:11:42 OK 3_commit_push.sql (1.75ms)14762026/10/01 10:11:42 goose: up to current file version: 314772026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.69ms)14782026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000014792026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads14802026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.2ms)14812026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.49ms)14822026/10/01 10:11:42 INFO Vacuumed table table=closures14832026/10/01 10:11:42 OK 3_commit_push.sql (898.59µs)14842026/10/01 10:11:42 goose: up to current file version: 314852026/10/01 10:11:42 INFO Vacuumed table table=objects14862026/10/01 10:11:42 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LjMwOTFiZGJjLTJiMzktNGVhMy05MjQxLTI1MzZkNGE5NzA5NXgxNzkwODQ5NTAyNDA5NTc3NDY3 parts=1014872026/10/01 10:11:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14882026-10-01 10:11:42.838 UTC [748] ERROR: relation "goose_db_version" does not exist at character 3614892026-10-01 10:11:42.838 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14902026/10/01 10:11:42 INFO Completed upload id=114912026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures14922026/10/01 10:11:42 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001493--- PASS: TestService_createPendingClosureHandler (0.96s)1494=== CONT TestPush_SignsNarinfosOfItsPendingObjects14952026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures14962026/10/01 10:11:42 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14972026/10/01 10:11:42 WARN Found objects in DB but missing from S3, will re-upload count=11498--- PASS: TestService_verifyS3Integrity (0.96s)1499=== CONT TestClientErrorHandling1500=== RUN TestClientErrorHandling/InvalidStorePath1501=== PAUSE TestClientErrorHandling/InvalidStorePath1502=== RUN TestClientErrorHandling/InvalidAuthToken1503=== PAUSE TestClientErrorHandling/InvalidAuthToken1504=== RUN TestClientErrorHandling/ServerNotAvailable1505=== PAUSE TestClientErrorHandling/ServerNotAvailable1506=== CONT TestPush_RejectsBadRequests15072026/10/01 10:11:42 OK 20241026095416_initial_model.sql (23.29ms)15082026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)15092026/10/01 10:11:42 OK 20251218171726_add_pins.sql (4.9ms)15102026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (5.49ms)15112026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.37ms)15122026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=015132026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (5.09ms)15142026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.08ms)15152026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000015162026/10/01 10:11:42 WARN Force mode enabled - objects will be deleted immediately without grace period15172026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.7ms)15182026-10-01 10:11:42.898 UTC [771] ERROR: relation "goose_db_version" does not exist at character 3615192026-10-01 10:11:42.898 UTC [771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15202026/10/01 10:11:42 INFO Received uploads request method=POST path=/api/pending_closures15212026/10/01 10:11:42 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=015222026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.26ms)15232026/10/01 10:11:42 INFO Vacuumed table table=pending_closures15242026/10/01 10:11:42 INFO Vacuumed table table=pending_objects15252026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads15262026/10/01 10:11:42 INFO Vacuumed table table=closures15272026/10/01 10:11:42 OK 3_commit_push.sql (2.43ms)15282026/10/01 10:11:42 goose: up to current file version: 315292026/10/01 10:11:42 INFO Vacuumed table table=objects1530--- PASS: TestGCMetrics (0.73s)1531=== CONT TestClientCADerivations15322026/10/01 10:11:42 OK 20241026095416_initial_model.sql (11.48ms)1533=== NAME TestClientWithDependencies1534 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2480205420/001/store/jg6snfl753brhscpcaf7k0a3hf93i97b-test-script15352026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)15362026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.11ms)15372026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)15382026-10-01 10:11:42.928 UTC [792] ERROR: relation "goose_db_version" does not exist at character 3615392026-10-01 10:11:42.928 UTC [792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15402026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.42ms)15412026-10-01 10:11:42.932 UTC [793] ERROR: relation "goose_db_version" does not exist at character 3615422026-10-01 10:11:42.932 UTC [793] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15432026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.31ms)15442026/10/01 10:11:42 INFO lead: acquired remote=192.0.2.1:123415452026/10/01 10:11:42 INFO lead: released remote=192.0.2.1:123415462026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.43ms)1547--- PASS: TestLeadEndsOnShutdown (0.62s)15482026/10/01 10:11:42 goose: successfully migrated database to version: 202609231200001549=== CONT TestCacheStatsHandler1550=== NAME TestClientWithDependencies1551 client_integration_test.go:615: Found 1 dependencies (including self)15522026/10/01 10:11:42 OK 1_commit_pending_closure.sql (17.64ms)15532026/10/01 10:11:42 OK 20241026095416_initial_model.sql (20.04ms)15542026/10/01 10:11:42 OK 20241026095416_initial_model.sql (12.52ms)15552026/10/01 10:11:42 OK 2_object_stats_trigger.sql (3.14ms)15562026/10/01 10:11:42 OK 3_commit_push.sql (924.93µs)15572026/10/01 10:11:42 goose: up to current file version: 315582026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (4.36ms)15592026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)15602026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.52ms)15612026/10/01 10:11:42 OK 20251218171726_add_pins.sql (4.1ms)15622026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)15632026-10-01 10:11:42.966 UTC [813] ERROR: relation "goose_db_version" does not exist at character 3615642026-10-01 10:11:42.966 UTC [813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15652026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)15662026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.79ms)15672026/10/01 10:11:42 OK 20260905000000_add_claims.sql (2.83ms)15682026/10/01 10:11:42 INFO lead: acquired remote=192.0.2.1:123415692026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.67ms)15702026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (3.15ms)15712026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.21ms)15722026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000015732026/10/01 10:11:42 INFO Aborted multipart uploads count=0 kept=015742026/10/01 10:11:42 OK 20260923120000_add_pushes.sql (2.15ms)15752026/10/01 10:11:42 goose: successfully migrated database to version: 2026092312000015762026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.41ms)15772026-10-01 10:11:42.977 UTC [831] ERROR: relation "goose_db_version" does not exist at character 3615782026-10-01 10:11:42.977 UTC [831] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15792026/10/01 10:11:42 OK 1_commit_pending_closure.sql (2.47ms)15802026/10/01 10:11:42 OK 2_object_stats_trigger.sql (2.22ms)15812026/10/01 10:11:42 OK 2_object_stats_trigger.sql (1.85ms)15822026/10/01 10:11:42 OK 3_commit_push.sql (1.78ms)15832026/10/01 10:11:42 goose: up to current file version: 315842026/10/01 10:11:42 OK 3_commit_push.sql (1.88ms)15852026/10/01 10:11:42 goose: up to current file version: 315862026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.41ms)15872026/10/01 10:11:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015882026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)15892026/10/01 10:11:42 INFO Vacuumed table table=pending_closures15902026/10/01 10:11:42 OK 20251218171726_add_pins.sql (3.63ms)15912026/10/01 10:11:42 INFO Vacuumed table table=pending_objects15922026/10/01 10:11:42 INFO Vacuumed table table=multipart_uploads1593--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.92s)1594=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit15952026/10/01 10:11:42 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)15962026/10/01 10:11:42 OK 20241026095416_initial_model.sql (9.35ms)15972026/10/01 10:11:42 INFO Vacuumed table table=closures15982026/10/01 10:11:42 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)15992026/10/01 10:11:42 OK 20260905000000_add_claims.sql (3.98ms)16002026/10/01 10:11:42 INFO Vacuumed table table=objects16012026/10/01 10:11:42 OK 20260920000000_drop_claims.sql (2.12ms)16022026/10/01 10:11:42 OK 20251218171726_add_pins.sql (2.99ms)16032026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.86ms)16042026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000016052026/10/01 10:11:43 INFO Aborted multipart uploads count=0 kept=016062026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)16072026/10/01 10:11:43 WARN Force mode enabled - objects will be deleted immediately without grace period16082026/10/01 10:11:43 OK 1_commit_pending_closure.sql (1.85ms)16092026/10/01 10:11:43 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=016102026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.21ms)16112026/10/01 10:11:43 OK 3_commit_push.sql (1.97ms)16122026/10/01 10:11:43 goose: up to current file version: 316132026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.9ms)16142026/10/01 10:11:43 INFO Vacuumed table table=pending_closures16152026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (1.99ms)16162026/10/01 10:11:43 INFO Vacuumed table table=pending_objects16172026/10/01 10:11:43 INFO Vacuumed table table=multipart_uploads16182026/10/01 10:11:43 INFO Vacuumed table table=closures16192026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.77ms)16202026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000016212026/10/01 10:11:43 INFO Vacuumed table table=objects1622--- PASS: TestPushDedupSurvivesConcurrentGC (0.86s)1623=== CONT TestReadRedirectKeepsNarinfoProxied16242026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.48ms)16252026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.62ms)16262026-10-01 10:11:43.016 UTC [837] ERROR: relation "goose_db_version" does not exist at character 3616272026-10-01 10:11:43.016 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16282026/10/01 10:11:43 OK 3_commit_push.sql (1.28ms)16292026/10/01 10:11:43 goose: up to current file version: 316302026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes16312026/10/01 10:11:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16322026/10/01 10:11:43 OK 20241026095416_initial_model.sql (10.86ms)16332026/10/01 10:11:43 INFO Uploading jg6snfl753brhscpcaf7k0a3hf93i97b-test-script (136B)16342026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)1635--- PASS: TestPushWaitsForSweepHoldingRow (1.15s)1636=== CONT TestReadRedirectNar16372026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16382026/10/01 10:11:43 WARN Failed to register uploaded object key=log/5wjqlx2bqz4nfl7pkpsg85c2jipxwzkr-test-script.drv error="server returned 404: 404 page not found\n"16392026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.2ms)16402026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16412026/10/01 10:11:43 WARN Failed to register uploaded object key=jg6snfl753brhscpcaf7k0a3hf93i97b.ls error="server returned 404: 404 page not found\n"16422026/10/01 10:11:43 INFO Signed narinfos id=1 count=116432026/10/01 10:11:43 INFO Uploading 1 narinfos16442026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (5.66ms)16452026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete16462026/10/01 10:11:43 WARN Failed to register uploaded object key=jg6snfl753brhscpcaf7k0a3hf93i97b.narinfo error="server returned 404: 404 page not found\n"16472026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.19ms)16482026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.02ms)16492026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.27ms)16502026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000016512026/10/01 10:11:43 INFO Upload complete. (72ms)16522026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.28ms)16532026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.42ms)1654=== NAME TestClientWithDependencies1655 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2480205420/001/store) requires matching store prefix16562026/10/01 10:11:43 OK 3_commit_push.sql (2ms)16572026/10/01 10:11:43 goose: up to current file version: 316582026-10-01 10:11:43.061 UTC [876] ERROR: relation "goose_db_version" does not exist at character 3616592026-10-01 10:11:43.061 UTC [876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1660--- PASS: TestClientWithDependencies (1.00s)1661=== CONT TestPush_CompleteCommitsEveryRoot16622026/10/01 10:11:43 OK 20241026095416_initial_model.sql (11.05ms)16632026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)16642026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.27ms)16652026-10-01 10:11:43.096 UTC [898] ERROR: relation "goose_db_version" does not exist at character 3616662026-10-01 10:11:43.096 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16672026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)16682026/10/01 10:11:43 OK 20260905000000_add_claims.sql (5.06ms)16692026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.51ms)16702026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (3.04ms)16712026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000016722026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.1ms)16732026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.14ms)16742026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)16752026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.58ms)16762026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.99ms)16772026/10/01 10:11:43 OK 3_commit_push.sql (2.51ms)16782026/10/01 10:11:43 goose: up to current file version: 316792026/10/01 10:11:43 INFO lead: released remote=192.0.2.1:123416802026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)16812026-10-01 10:11:43.123 UTC [935] ERROR: relation "goose_db_version" does not exist at character 3616822026-10-01 10:11:43.123 UTC [935] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16832026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.23ms)16842026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.54ms)1685--- PASS: TestReadProxyHead (0.57s)1686=== CONT TestReadProxyDisabled16872026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.19ms)16882026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000016892026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.47ms)16902026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.39ms)16912026/10/01 10:11:43 OK 3_commit_push.sql (911.66µs)16922026/10/01 10:11:43 goose: up to current file version: 316932026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.45ms)16942026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)16952026-10-01 10:11:43.140 UTC [972] ERROR: relation "goose_db_version" does not exist at character 3616962026-10-01 10:11:43.140 UTC [972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16972026/10/01 10:11:43 OK 20251218171726_add_pins.sql (1.94ms)1698--- PASS: TestGCBugBareHashReferences (0.88s)1699=== CONT TestPush_OverlappingRootsStoreOneRowPerKey17002026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)17012026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures17022026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.69ms)17032026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.14ms)17042026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.9ms)17052026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000017062026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.03ms)17072026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.86ms)17082026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.99ms)1709=== NAME TestPinProtectsFromGC1710 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3519866355/001/store/99xw70nh0s85bfr9gc94k63ri53n92mf-pinned-file.txt1711 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3519866355/001/store/whrnapnxqi3h2n519x4r49hhaivwiv51-unpinned-file.txt17122026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)17132026/10/01 10:11:43 OK 3_commit_push.sql (1.55ms)17142026/10/01 10:11:43 goose: up to current file version: 317152026-10-01 10:11:43.167 UTC [1025] ERROR: relation "goose_db_version" does not exist at character 3617162026-10-01 10:11:43.167 UTC [1025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17172026/10/01 10:11:43 OK 20251218171726_add_pins.sql (10.91ms)17182026/10/01 10:11:43 INFO lead: acquired remote=192.0.2.1:123417192026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)1720--- PASS: TestService_Rustfstest (0.50s)1721=== CONT TestReadProxyRootRedirectsToIndexHTML17222026/10/01 10:11:43 INFO lead: released remote=192.0.2.1:12341723--- PASS: TestLeadElectsOneAndHandsOver (0.83s)1724=== CONT TestReadRedirectUsesPublicS3URL17252026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.89ms)17262026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.41ms)17272026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.21ms)17282026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000017292026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.54ms)17302026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.71ms)17312026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)17322026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.16ms)17332026/10/01 10:11:43 OK 3_commit_push.sql (1.47ms)17342026/10/01 10:11:43 goose: up to current file version: 317352026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.75ms)17362026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)17372026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.24ms)17382026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures17392026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.6ms)17402026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.19ms)17412026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000017422026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.7ms)17432026/10/01 10:11:43 OK 2_object_stats_trigger.sql (3.01ms)17442026/10/01 10:11:43 OK 3_commit_push.sql (1.76ms)17452026/10/01 10:11:43 goose: up to current file version: 317462026/10/01 10:11:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17472026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures17482026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures1749--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.55s)1750=== CONT TestReadProxyConditionalGet17512026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes17522026/10/01 10:11:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17532026/10/01 10:11:43 INFO Uploading 99xw70nh0s85bfr9gc94k63ri53n92mf-pinned-file.txt (128B)17542026/10/01 10:11:43 WARN Failed to register uploaded object key=99xw70nh0s85bfr9gc94k63ri53n92mf.ls error="server returned 404: 404 page not found\n"17552026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17562026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17572026/10/01 10:11:43 INFO Signed narinfos id=1 count=117582026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures17592026/10/01 10:11:43 INFO Uploading 1 narinfos17602026/10/01 10:11:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17612026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes17622026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete17632026/10/01 10:11:43 WARN Failed to register uploaded object key=99xw70nh0s85bfr9gc94k63ri53n92mf.narinfo error="server returned 404: 404 page not found\n"17642026-10-01 10:11:43.253 UTC [1178] ERROR: relation "goose_db_version" does not exist at character 3617652026-10-01 10:11:43.253 UTC [1178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17662026-10-01 10:11:43.253 UTC [1181] ERROR: relation "goose_db_version" does not exist at character 3617672026-10-01 10:11:43.253 UTC [1181] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17682026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes17692026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures17702026/10/01 10:11:43 INFO Upload complete. (82ms)17712026/10/01 10:11:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17722026/10/01 10:11:43 INFO Uploading 56h1s4m9ixra6cxfap1krkjnm06h27xx-shared-dep (136B)17732026/10/01 10:11:43 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17742026/10/01 10:11:43 INFO Uploading 9a7lqw7hcxlz6gn4wfn2h0wsrshba9jk-a (216B)17752026/10/01 10:11:43 INFO Uploading 89yyyi1zyrdy82xnbmn7cm5lwvg4x78d-shared-dep (136B)17762026/10/01 10:11:43 INFO Uploading m95cn1dm6kb8mmp0h0j3c6z7j50h1syh-top (224B)17772026/10/01 10:11:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17782026/10/01 10:11:43 INFO Uploading 41gj3g55n6r0lhlfq9ih57rzl8vbab5p-shared-dep (136B)17792026/10/01 10:11:43 INFO Uploading j5pmczid29flkz10ymswm1q79w19vbcx-b (216B)17802026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures17812026/10/01 10:11:43 OK 20241026095416_initial_model.sql (10.57ms)17822026/10/01 10:11:43 OK 20241026095416_initial_model.sql (11.03ms)17832026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)17842026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)17852026/10/01 10:11:43 WARN Failed to register uploaded object key=3sjvpfzfkrbpfsh8hhc7sahxi61p170n.ls error="server returned 404: 404 page not found\n"17862026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.84ms)17872026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.33ms)17882026/10/01 10:11:43 WARN Failed to register uploaded object key=89yyyi1zyrdy82xnbmn7cm5lwvg4x78d.ls error="server returned 404: 404 page not found\n"17892026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17902026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/1874hhh72bydh739fp77y9f87c85r91c46n1vaaw95yrn0y3l7jb.nar.zst error="server returned 404: 404 page not found\n"17912026/10/01 10:11:43 WARN Failed to register uploaded object key=9a7lqw7hcxlz6gn4wfn2h0wsrshba9jk.ls error="server returned 404: 404 page not found\n"17922026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17932026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17942026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/0ncxic247vzv4xc7yl8kcib8cmmwis6hjy53gv19dn0v8pz2wci3.nar.zst error="server returned 404: 404 page not found\n"17952026/10/01 10:11:43 WARN Failed to register uploaded object key=56h1s4m9ixra6cxfap1krkjnm06h27xx.ls error="server returned 404: 404 page not found\n"17962026/10/01 10:11:43 WARN Failed to register uploaded object key=02avwf3nik5nllyp45h51b72blmlrkpa.ls error="server returned 404: 404 page not found\n"17972026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17982026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/0l14xsdywjqcbzsj8xk9zk0rz64z4dfjx14cjs72jnfymar5jpgd.nar.zst error="server returned 404: 404 page not found\n"17992026/10/01 10:11:43 INFO Signed narinfos id=1 count=318002026/10/01 10:11:43 INFO Uploading 3 narinfos18012026/10/01 10:11:43 WARN Failed to register uploaded object key=j5pmczid29flkz10ymswm1q79w19vbcx.ls error="server returned 404: 404 page not found\n"18022026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18032026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18042026/10/01 10:11:43 WARN Failed to register uploaded object key=41gj3g55n6r0lhlfq9ih57rzl8vbab5p.ls error="server returned 404: 404 page not found\n"18052026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)18062026/10/01 10:11:43 WARN Failed to register uploaded object key=m95cn1dm6kb8mmp0h0j3c6z7j50h1syh.ls error="server returned 404: 404 page not found\n"18072026/10/01 10:11:43 INFO Signed narinfos id=1 count=218082026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)18092026/10/01 10:11:43 INFO Signed narinfos id=1 count=218102026/10/01 10:11:43 INFO Uploading 2 narinfos18112026-10-01 10:11:43.291 UTC [1233] ERROR: relation "goose_db_version" does not exist at character 3618122026-10-01 10:11:43.291 UTC [1233] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18132026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18142026/10/01 10:11:43 INFO Signed narinfos id=2 count=218152026/10/01 10:11:43 INFO Uploading 4 narinfos18162026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.59ms)18172026/10/01 10:11:43 WARN Failed to register uploaded object key=9a7lqw7hcxlz6gn4wfn2h0wsrshba9jk.narinfo error="server returned 404: 404 page not found\n"18182026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.62ms)18192026/10/01 10:11:43 WARN Failed to register uploaded object key=3sjvpfzfkrbpfsh8hhc7sahxi61p170n.narinfo error="server returned 404: 404 page not found\n"18202026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete18212026/10/01 10:11:43 WARN Failed to register uploaded object key=56h1s4m9ixra6cxfap1krkjnm06h27xx.narinfo error="server returned 404: 404 page not found\n"18222026/10/01 10:11:43 WARN Failed to register uploaded object key=89yyyi1zyrdy82xnbmn7cm5lwvg4x78d.narinfo error="server returned 404: 404 page not found\n"18232026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.12ms)18242026/10/01 10:11:43 WARN Failed to register uploaded object key=m95cn1dm6kb8mmp0h0j3c6z7j50h1syh.narinfo error="server returned 404: 404 page not found\n"18252026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete18262026/10/01 10:11:43 WARN Failed to register uploaded object key=41gj3g55n6r0lhlfq9ih57rzl8vbab5p.narinfo error="server returned 404: 404 page not found\n"18272026/10/01 10:11:43 WARN Failed to register uploaded object key=j5pmczid29flkz10ymswm1q79w19vbcx.narinfo error="server returned 404: 404 page not found\n"18282026/10/01 10:11:43 WARN Failed to register uploaded object key=02avwf3nik5nllyp45h51b72blmlrkpa.narinfo error="server returned 404: 404 page not found\n"18292026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.78ms)18302026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.2ms)18312026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000018322026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.62ms)18332026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000018342026/10/01 10:11:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18352026/10/01 10:11:43 WARN Failed to register uploaded object key=41gj3g55n6r0lhlfq9ih57rzl8vbab5p.narinfo error="server returned 404: 404 page not found\n"18362026-10-01 10:11:43.298 UTC [1235] ERROR: relation "goose_db_version" does not exist at character 3618372026-10-01 10:11:43.298 UTC [1235] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18382026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.03ms)18392026/10/01 10:11:43 INFO Upload complete. (96ms)1840=== NAME TestClientMultipleUploads1841 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3869363327/001/store/b9fdaafnsx4nx7cx9qhfc5sskb5vcpns-test-file-0.txt18422026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.64ms)18432026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.11ms)1844=== NAME TestClientPushesUseOnePush1845 client_pushes_test.go:97: Retrieved narinfo from S3:1846 StorePath: /build/TestClientPushesUseOnePush2405112661/001/store/56h1s4m9ixra6cxfap1krkjnm06h27xx-shared-dep1847 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1848 Compression: zstd1849 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821850 NarSize: 1361851 References: 1852 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18532026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.98ms)18542026/10/01 10:11:43 OK 3_commit_push.sql (1.32ms)18552026/10/01 10:11:43 goose: up to current file version: 318562026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.29ms)18572026/10/01 10:11:43 OK 3_commit_push.sql (2.05ms)18582026/10/01 10:11:43 goose: up to current file version: 318592026/10/01 10:11:43 INFO Upload complete. (90ms)1860 client_pushes_test.go:97: Retrieved narinfo from S3:1861 StorePath: /build/TestClientPushesUseOnePush2405112661/001/store/9a7lqw7hcxlz6gn4wfn2h0wsrshba9jk-a1862 URL: nar/0l14xsdywjqcbzsj8xk9zk0rz64z4dfjx14cjs72jnfymar5jpgd.nar.zst1863 Compression: zstd1864 NarHash: sha256:0l14xsdywjqcbzsj8xk9zk0rz64z4dfjx14cjs72jnfymar5jpgd1865 NarSize: 2161866 References: /build/TestClientPushesUseOnePush2405112661/001/store/56h1s4m9ixra6cxfap1krkjnm06h27xx-shared-dep1867 CA: text:sha256:1l9wn49p5hbz9baq0m1w6c266rh7fy4xl28rznj7nd0mgm7xcw561868=== NAME TestClientSharedPathCommittedMidPush1869 client_integration_test.go:680: Retrieved narinfo from S3:1870 StorePath: /build/TestClientSharedPathCommittedMidPush2757805751/001/store/89yyyi1zyrdy82xnbmn7cm5lwvg4x78d-shared-dep1871 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1872 Compression: zstd1873 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821874 NarSize: 1361875 References: 1876 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18772026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)18782026/10/01 10:11:43 INFO Completed upload id=118792026/10/01 10:11:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1880=== NAME TestClientPushesUseOnePush1881 client_pushes_test.go:97: Retrieved narinfo from S3:1882 StorePath: /build/TestClientPushesUseOnePush2405112661/001/store/3sjvpfzfkrbpfsh8hhc7sahxi61p170n-b1883 URL: nar/0l14xsdywjqcbzsj8xk9zk0rz64z4dfjx14cjs72jnfymar5jpgd.nar.zst1884 Compression: zstd1885 NarHash: sha256:0l14xsdywjqcbzsj8xk9zk0rz64z4dfjx14cjs72jnfymar5jpgd1886 NarSize: 2161887 References: /build/TestClientPushesUseOnePush2405112661/001/store/56h1s4m9ixra6cxfap1krkjnm06h27xx-shared-dep1888 CA: text:sha256:1l9wn49p5hbz9baq0m1w6c266rh7fy4xl28rznj7nd0mgm7xcw561889=== NAME TestClientSharedPathCommittedMidPush1890 client_integration_test.go:680: Retrieved narinfo from S3:1891 StorePath: /build/TestClientSharedPathCommittedMidPush2757805751/001/store/m95cn1dm6kb8mmp0h0j3c6z7j50h1syh-top1892 URL: nar/1874hhh72bydh739fp77y9f87c85r91c46n1vaaw95yrn0y3l7jb.nar.zst1893 Compression: zstd1894 NarHash: sha256:1874hhh72bydh739fp77y9f87c85r91c46n1vaaw95yrn0y3l7jb1895 NarSize: 2241896 References: /build/TestClientSharedPathCommittedMidPush2757805751/001/store/89yyyi1zyrdy82xnbmn7cm5lwvg4x78d-shared-dep1897 CA: text:sha256:1npppr9f5gxpddany8k3xfij4mlzkr40f5k86m7ca474q65dzii918982026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.89ms)18992026/10/01 10:11:43 INFO Completed upload id=219002026/10/01 10:11:43 INFO Upload complete. (110ms)19012026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures1902=== NAME TestClientFallsBackToClosures1903 client_pushes_test.go:112: Retrieved narinfo from S3:1904 StorePath: /build/TestClientFallsBackToClosures2030168940/001/store/41gj3g55n6r0lhlfq9ih57rzl8vbab5p-shared-dep1905 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1906 Compression: zstd1907 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821908 NarSize: 1361909 References: 1910 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19112026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)1912 client_pushes_test.go:112: Retrieved narinfo from S3:1913 StorePath: /build/TestClientFallsBackToClosures2030168940/001/store/02avwf3nik5nllyp45h51b72blmlrkpa-a1914 URL: nar/0ncxic247vzv4xc7yl8kcib8cmmwis6hjy53gv19dn0v8pz2wci3.nar.zst1915 Compression: zstd1916 NarHash: sha256:0ncxic247vzv4xc7yl8kcib8cmmwis6hjy53gv19dn0v8pz2wci31917 NarSize: 2161918 References: /build/TestClientFallsBackToClosures2030168940/001/store/41gj3g55n6r0lhlfq9ih57rzl8vbab5p-shared-dep1919 CA: text:sha256:19dfhvql2ksvfzp668x0bd61pjpbm8r4kf4gvsljfgaclprswzlm1920--- PASS: TestClientPushesUseOnePush (0.84s)1921=== CONT TestReadProxyRangeRequest1922=== NAME TestClientFallsBackToClosures1923 client_pushes_test.go:112: Retrieved narinfo from S3:1924 StorePath: /build/TestClientFallsBackToClosures2030168940/001/store/j5pmczid29flkz10ymswm1q79w19vbcx-b1925 URL: nar/0ncxic247vzv4xc7yl8kcib8cmmwis6hjy53gv19dn0v8pz2wci3.nar.zst1926 Compression: zstd1927 NarHash: sha256:0ncxic247vzv4xc7yl8kcib8cmmwis6hjy53gv19dn0v8pz2wci31928 NarSize: 2161929--- PASS: TestClientSharedPathCommittedMidPush (0.79s)1930=== CONT TestService_AuthMiddleware_OIDC19312026/10/01 10:11:43 OK 20241026095416_initial_model.sql (10.39ms)1932=== NAME TestClientFallsBackToClosures1933 References: /build/TestClientFallsBackToClosures2030168940/001/store/41gj3g55n6r0lhlfq9ih57rzl8vbab5p-shared-dep1934 CA: text:sha256:19dfhvql2ksvfzp668x0bd61pjpbm8r4kf4gvsljfgaclprswzlm19352026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.61ms)19362026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)19372026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.42ms)19382026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.1ms)19392026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000019402026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.62ms)1941--- PASS: TestClientFallsBackToClosures (0.89s)1942=== CONT TestService_AuthMiddleware_MTLSBoundSubjects19432026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.04ms)19442026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.39ms)19452026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)19462026/10/01 10:11:43 OK 3_commit_push.sql (1.09ms)19472026/10/01 10:11:43 goose: up to current file version: 319482026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures19492026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.44ms)19502026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.33ms)19512026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.41ms)19522026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000019532026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.35ms)19542026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes19552026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.56ms)19562026/10/01 10:11:43 OK 3_commit_push.sql (1.12ms)19572026/10/01 10:11:43 goose: up to current file version: 319582026/10/01 10:11:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19592026/10/01 10:11:43 INFO Uploading whrnapnxqi3h2n519x4r49hhaivwiv51-unpinned-file.txt (128B)1960=== NAME TestClientMultipleUploads1961 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3869363327/001/store/sbyy4vlx9gb4bknmhya6b5l7i812x536-test-file-1.txt19622026/10/01 10:11:43 WARN Failed to register uploaded object key=whrnapnxqi3h2n519x4r49hhaivwiv51.ls error="server returned 404: 404 page not found\n"19632026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19642026/10/01 10:11:43 INFO Signed narinfos id=2 count=119652026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19662026/10/01 10:11:43 INFO Uploading 1 narinfos19672026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/2/complete19682026/10/01 10:11:43 WARN Failed to register uploaded object key=whrnapnxqi3h2n519x4r49hhaivwiv51.narinfo error="server returned 404: 404 page not found\n"19692026-10-01 10:11:43.352 UTC [1291] ERROR: relation "goose_db_version" does not exist at character 3619702026-10-01 10:11:43.352 UTC [1291] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19712026/10/01 10:11:43 INFO Upload complete. (51ms)1972--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.94s)1973=== CONT TestService_ReadScope_PublicByDefault19742026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes19752026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.75ms)19762026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)19772026/10/01 10:11:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40285/oidc19782026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19792026/10/01 10:11:43 INFO Signed narinfos id=1 count=11980--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.53s)1981=== CONT TestService_ReadAuthMiddleware19822026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.4ms)19832026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)1984=== NAME TestClientMultipleUploads1985 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3869363327/001/store/5qscgnkfacfpfyvv3y6mpwcf5n4lv0nk-test-file-2.txt19862026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.66ms)19872026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.57ms)1988=== NAME TestClientIntegration1989 client_integration_test.go:286: Created store path: /build/TestClientIntegration1431309653/002/store/hwqn0an6s4ad4bha7hx0qhcp0pzqqavd-test-file.txt19902026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.96ms)1991=== RUN TestPush_RejectsBadRequests/no_roots19922026/10/01 10:11:43 goose: successfully migrated database to version: 202609231200001993=== PAUSE TestPush_RejectsBadRequests/no_roots1994=== RUN TestPush_RejectsBadRequests/no_objects1995=== PAUSE TestPush_RejectsBadRequests/no_objects1996=== RUN TestPush_RejectsBadRequests/bad_root1997=== PAUSE TestPush_RejectsBadRequests/bad_root1998=== RUN TestPush_RejectsBadRequests/root_not_in_objects1999=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2000=== CONT TestService_RequireScope_OIDC20012026/10/01 10:11:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures20022026/10/01 10:11:43 INFO Garbage collection started20032026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.29ms)20042026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.56ms)20052026/10/01 10:11:43 OK 3_commit_push.sql (11.04ms)20062026/10/01 10:11:43 goose: up to current file version: 320072026/10/01 10:11:43 INFO Aborted multipart uploads count=0 kept=020082026/10/01 10:11:43 WARN Force mode enabled - objects will be deleted immediately without grace period20092026-10-01 10:11:43.428 UTC [1388] ERROR: relation "goose_db_version" does not exist at character 3620102026-10-01 10:11:43.428 UTC [1388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20112026-10-01 10:11:43.431 UTC [1390] ERROR: relation "goose_db_version" does not exist at character 3620122026-10-01 10:11:43.431 UTC [1390] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20132026/10/01 10:11:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=020142026/10/01 10:11:43 INFO Vacuumed table table=pending_closures20152026/10/01 10:11:43 INFO Vacuumed table table=pending_objects20162026/10/01 10:11:43 INFO Vacuumed table table=multipart_uploads20172026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.29ms)20182026/10/01 10:11:43 INFO Vacuumed table table=closures20192026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)20202026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.67ms)20212026/10/01 10:11:43 INFO Vacuumed table table=objects20222026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)20232026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.79ms)20242026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.64ms)20252026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)20262026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)20272026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.75ms)20282026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.45ms)20292026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.45ms)20302026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.27ms)20312026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.64ms)20322026/10/01 10:11:43 goose: successfully migrated database to version: 202609231200002033--- PASS: TestCacheStatsHandler (0.53s)2034=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded20352026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.18ms)20362026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000020372026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.55ms)20382026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.29ms)20392026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.76ms)20402026/10/01 10:11:43 OK 3_commit_push.sql (1.57ms)20412026/10/01 10:11:43 goose: up to current file version: 320422026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.09ms)20432026/10/01 10:11:43 OK 3_commit_push.sql (1.42ms)20442026/10/01 10:11:43 goose: up to current file version: 320452026-10-01 10:11:43.472 UTC [1429] ERROR: relation "goose_db_version" does not exist at character 3620462026-10-01 10:11:43.472 UTC [1429] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20472026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes20482026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes20492026/10/01 10:11:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20502026/10/01 10:11:43 INFO Uploading hwqn0an6s4ad4bha7hx0qhcp0pzqqavd-test-file.txt (152B)20512026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes20522026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20532026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20542026/10/01 10:11:43 WARN Failed to register uploaded object key=hwqn0an6s4ad4bha7hx0qhcp0pzqqavd.ls error="server returned 404: 404 page not found\n"20552026/10/01 10:11:43 INFO Signed narinfos id=1 count=120562026/10/01 10:11:43 INFO Uploading 1 narinfos20572026/10/01 10:11:43 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20582026/10/01 10:11:43 INFO Uploading b9fdaafnsx4nx7cx9qhfc5sskb5vcpns-test-file-0.txt (160B)20592026/10/01 10:11:43 INFO Uploading sbyy4vlx9gb4bknmhya6b5l7i812x536-test-file-1.txt (160B)20602026/10/01 10:11:43 INFO Uploading 5qscgnkfacfpfyvv3y6mpwcf5n4lv0nk-test-file-2.txt (160B)20612026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.23ms)20622026/10/01 10:11:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38079/oidc20632026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete20642026/10/01 10:11:43 WARN Failed to register uploaded object key=hwqn0an6s4ad4bha7hx0qhcp0pzqqavd.narinfo error="server returned 404: 404 page not found\n"20652026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)20662026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20672026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.15ms)20682026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20692026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20702026/10/01 10:11:43 WARN Failed to register uploaded object key=5qscgnkfacfpfyvv3y6mpwcf5n4lv0nk.ls error="server returned 404: 404 page not found\n"20712026/10/01 10:11:43 WARN Failed to register uploaded object key=sbyy4vlx9gb4bknmhya6b5l7i812x536.ls error="server returned 404: 404 page not found\n"20722026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20732026/10/01 10:11:43 WARN Failed to register uploaded object key=b9fdaafnsx4nx7cx9qhfc5sskb5vcpns.ls error="server returned 404: 404 page not found\n"20742026/10/01 10:11:43 INFO Signed narinfos id=1 count=320752026/10/01 10:11:43 INFO Uploading 3 narinfos20762026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)20772026-10-01 10:11:43.496 UTC [1451] ERROR: relation "goose_db_version" does not exist at character 3620782026-10-01 10:11:43.496 UTC [1451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20792026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete20802026/10/01 10:11:43 WARN Failed to register uploaded object key=sbyy4vlx9gb4bknmhya6b5l7i812x536.narinfo error="server returned 404: 404 page not found\n"20812026/10/01 10:11:43 INFO Upload complete. (71ms)20822026/10/01 10:11:43 WARN Failed to register uploaded object key=b9fdaafnsx4nx7cx9qhfc5sskb5vcpns.narinfo error="server returned 404: 404 page not found\n"20832026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete20842026/10/01 10:11:43 WARN Failed to register uploaded object key=5qscgnkfacfpfyvv3y6mpwcf5n4lv0nk.narinfo error="server returned 404: 404 page not found\n"20852026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.89ms)20862026-10-01 10:11:43.500 UTC [1468] ERROR: relation "goose_db_version" does not exist at character 3620872026-10-01 10:11:43.500 UTC [1468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20882026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.21ms)20892026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.92ms)20902026/10/01 10:11:43 goose: successfully migrated database to version: 202609231200002091--- PASS: TestReadRedirectKeepsNarinfoProxied (0.50s)2092=== CONT TestObjectStatsTrigger20932026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes20942026/10/01 10:11:43 OK 1_commit_pending_closure.sql (12.21ms)20952026/10/01 10:11:43 OK 20241026095416_initial_model.sql (14.07ms)20962026/10/01 10:11:43 OK 20241026095416_initial_model.sql (10.97ms)20972026/10/01 10:11:43 INFO Upload complete. (86ms)2098=== NAME TestClientMultipleUploads2099 client_integration_test.go:369: Uploaded 3 paths in 135.960175ms21002026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.05ms)21012026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)21022026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)2103=== NAME TestClientCADerivations2104 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations257425860/001/store/amv0s0r0c0hdm033qw79kh5f374pw0w0-ca-test21052026/10/01 10:11:43 OK 3_commit_push.sql (1.22ms)21062026/10/01 10:11:43 goose: up to current file version: 321072026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.5ms)21082026/10/01 10:11:43 OK 20251218171726_add_pins.sql (5.24ms)21092026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)2110--- PASS: TestClientMultipleUploads (0.80s)2111=== CONT TestOrphanedObjectsGC21122026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (6.15ms)21132026/10/01 10:11:43 OK 20260905000000_add_claims.sql (4.98ms)21142026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (1.9ms)21152026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.93ms)21162026/10/01 10:11:43 INFO All 1 paths already cached21172026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (3.07ms)21182026/10/01 10:11:43 goose: successfully migrated database to version: 202609231200002119=== NAME TestClientIntegration2120 client_integration_test.go:312: Retrieved narinfo from S3:2121 StorePath: /build/TestClientIntegration1431309653/002/store/hwqn0an6s4ad4bha7hx0qhcp0pzqqavd-test-file.txt2122 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2123 Compression: zstd2124 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk121252026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.53ms)2126 NarSize: 1522127 References: 2128 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12129--- PASS: TestReadRedirectNar (0.50s)2130=== CONT TestPendingCleanupUsesOneCutoff21312026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.43ms)21322026/10/01 10:11:43 goose: successfully migrated database to version: 202609231200002133=== NAME TestClientIntegration21342026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.94ms)2135 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2136 client_integration_test.go:313: Decompressed .ls content (64 bytes):2137 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2138 client_integration_test.go:316: Testing garbage collection...21392026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.77ms)21402026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.11ms)21412026/10/01 10:11:43 OK 3_commit_push.sql (2.14ms)21422026/10/01 10:11:43 goose: up to current file version: 321432026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.08ms)21442026/10/01 10:11:43 OK 3_commit_push.sql (1.57ms)21452026/10/01 10:11:43 goose: up to current file version: 32146=== NAME TestClientCADerivations2147 client_ca_test.go:139: Found 1 dependencies (including self)21482026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes21492026-10-01 10:11:43.568 UTC [1514] ERROR: relation "goose_db_version" does not exist at character 3621502026-10-01 10:11:43.568 UTC [1514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21512026/10/01 10:11:43 INFO Aborted multipart uploads count=0 kept=021522026/10/01 10:11:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures21532026/10/01 10:11:43 INFO Garbage collection started21542026/10/01 10:11:43 WARN Force mode enabled - objects will be deleted immediately without grace period21552026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete21562026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.51ms)21572026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)21582026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes21592026/10/01 10:11:43 INFO Aborted multipart uploads count=0 kept=021602026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.1ms)21612026/10/01 10:11:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=02162--- PASS: TestPush_CompleteCommitsEveryRoot (0.53s)2163=== CONT TestOrphanedObjectsGCStressTest21642026/10/01 10:11:43 WARN Force mode enabled - objects will be deleted immediately without grace period21652026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)21662026-10-01 10:11:43.595 UTC [1552] ERROR: relation "goose_db_version" does not exist at character 3621672026-10-01 10:11:43.595 UTC [1552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21682026/10/01 10:11:43 INFO Vacuumed table table=pending_closures21692026/10/01 10:11:43 OK 20260905000000_add_claims.sql (11.12ms)21702026/10/01 10:11:43 INFO Vacuumed table table=pending_objects21712026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (5.17ms)21722026/10/01 10:11:43 INFO Vacuumed table table=multipart_uploads21732026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.98ms)21742026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000021752026/10/01 10:11:43 OK 1_commit_pending_closure.sql (4.36ms)21762026/10/01 10:11:43 INFO Vacuumed table table=closures2177--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.48s)2178=== CONT TestService_NativeMTLS21792026/10/01 10:11:43 OK 20241026095416_initial_model.sql (11.05ms)21802026-10-01 10:11:43.621 UTC [1558] ERROR: relation "goose_db_version" does not exist at character 3621812026-10-01 10:11:43.621 UTC [1558] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2182--- PASS: TestReadProxyDisabled (0.49s)2183=== CONT TestService_AuthMiddleware_MTLSProxyHeader21842026/10/01 10:11:43 OK 2_object_stats_trigger.sql (4.37ms)21852026/10/01 10:11:43 INFO Vacuumed table table=objects21862026/10/01 10:11:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=021872026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/2/complete21882026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (4.86ms)21892026/10/01 10:11:43 OK 3_commit_push.sql (4.26ms)21902026/10/01 10:11:43 goose: up to current file version: 321912026/10/01 10:11:43 OK 20251218171726_add_pins.sql (5.9ms)21922026/10/01 10:11:43 INFO Vacuumed table table=pending_closures2193--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.64s)2194=== CONT TestMultipartCleanup21952026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (8.75ms)21962026/10/01 10:11:43 OK 20241026095416_initial_model.sql (12.79ms)21972026/10/01 10:11:43 INFO Vacuumed table table=pending_objects21982026/10/01 10:11:43 INFO Vacuumed table table=multipart_uploads21992026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (4.71ms)22002026/10/01 10:11:43 OK 20260905000000_add_claims.sql (7.28ms)22012026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.84ms)22022026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (7.33ms)22032026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)22042026/10/01 10:11:43 INFO Vacuumed table table=closures22052026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.48ms)22062026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000022072026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.38ms)22082026-10-01 10:11:43.660 UTC [1580] ERROR: relation "goose_db_version" does not exist at character 3622092026-10-01 10:11:43.660 UTC [1580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22102026-10-01 10:11:43.661 UTC [1584] ERROR: relation "goose_db_version" does not exist at character 3622112026-10-01 10:11:43.661 UTC [1584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22122026/10/01 10:11:43 INFO Vacuumed table table=objects22132026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.29ms)22142026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.84ms)22152026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.36ms)22162026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.21ms)22172026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000022182026/10/01 10:11:43 OK 3_commit_push.sql (2.38ms)22192026/10/01 10:11:43 goose: up to current file version: 322202026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.13ms)22212026/10/01 10:11:43 INFO Received push request method=POST path=/api/pushes22222026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.69ms)22232026/10/01 10:11:43 OK 3_commit_push.sql (1.22ms)22242026/10/01 10:11:43 goose: up to current file version: 32225--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.50s)2226=== CONT TestCreatePin_ReservedPins22272026/10/01 10:11:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22282026/10/01 10:11:43 INFO Uploading amv0s0r0c0hdm033qw79kh5f374pw0w0-ca-test (144B)22292026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.38ms)22302026/10/01 10:11:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22312026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.72ms)22322026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)22332026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)22342026/10/01 10:11:43 WARN Failed to register uploaded object key=log/fz7f29qsm8602y8dddd57n2a0rpcnm2v-ca-test.drv error="server returned 404: 404 page not found\n"22352026/10/01 10:11:43 WARN Failed to register uploaded object key=amv0s0r0c0hdm033qw79kh5f374pw0w0.ls error="server returned 404: 404 page not found\n"22362026/10/01 10:11:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22372026/10/01 10:11:43 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LmMxMWY4NTg3LWRiNzktNGI0NS1hNmU1LTQ5ZjljNjEyOWIyOXgxNzkwODQ5NTAzMjkyMjExMDc422382026/10/01 10:11:43 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"22392026/10/01 10:11:43 INFO Signed narinfos id=1 count=122402026/10/01 10:11:43 INFO Uploading 1 narinfos22412026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.87ms)22422026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.02ms)22432026/10/01 10:11:43 INFO Received complete push request method=POST path=/api/pushes/1/complete22442026/10/01 10:11:43 WARN Failed to register uploaded object key=amv0s0r0c0hdm033qw79kh5f374pw0w0.narinfo error="server returned 404: 404 page not found\n"22452026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)22462026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)22472026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.64ms)22482026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.83ms)22492026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.27ms)22502026/10/01 10:11:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LmMxMWY4NTg3LWRiNzktNGI0NS1hNmU1LTQ5ZjljNjEyOWIyOXgxNzkwODQ5NTAzMjkyMjExMDc4 parts=122512026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.14ms)2252--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.91s)2253=== CONT TestReadProxyNarinfo22542026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.74ms)22552026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000022562026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.94ms)22572026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000022582026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.29ms)22592026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.42ms)22602026/10/01 10:11:43 INFO Upload complete. (111ms)22612026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.69ms)22622026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.7ms)22632026/10/01 10:11:43 OK 3_commit_push.sql (1.45ms)22642026/10/01 10:11:43 goose: up to current file version: 322652026/10/01 10:11:43 OK 3_commit_push.sql (919.93µs)22662026/10/01 10:11:43 goose: up to current file version: 32267=== NAME TestClientCADerivations2268 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations257425860/001/store/amv0s0r0c0hdm033qw79kh5f374pw0w0-ca-test2269 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2270 Compression: zstd2271 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2272 NarSize: 1442273 References: 2274 Deriver: /build/TestClientCADerivations257425860/001/store/fz7f29qsm8602y8dddd57n2a0rpcnm2v-ca-test.drv2275 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2276 client_ca_test.go:185: Checking for realisation files in S3...22772026-10-01 10:11:43.702 UTC [1603] ERROR: relation "goose_db_version" does not exist at character 3622782026-10-01 10:11:43.702 UTC [1603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2279 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2280 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2281--- PASS: TestReadRedirectUsesPublicS3URL (0.53s)2282=== CONT TestServerTLSConfig2283=== RUN TestServerTLSConfig/no_client_CA2284=== PAUSE TestServerTLSConfig/no_client_CA2285=== RUN TestServerTLSConfig/missing_CA_file2286=== PAUSE TestServerTLSConfig/missing_CA_file2287=== RUN TestServerTLSConfig/not_a_PEM_file2288=== PAUSE TestServerTLSConfig/not_a_PEM_file2289=== CONT TestReadProxyInvalidPath22902026/10/01 10:11:43 OK 20241026095416_initial_model.sql (16.01ms)22912026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)2292--- PASS: TestReadProxyConditionalGet (0.51s)2293=== CONT TestMetricsInventory22942026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.71ms)22952026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)22962026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.73ms)22972026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.77ms)22982026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.19ms)22992026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000023002026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.18ms)23012026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.45ms)23022026-10-01 10:11:43.758 UTC [1628] ERROR: relation "goose_db_version" does not exist at character 3623032026-10-01 10:11:43.758 UTC [1628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23042026-10-01 10:11:43.759 UTC [1629] ERROR: relation "goose_db_version" does not exist at character 3623052026-10-01 10:11:43.759 UTC [1629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23062026/10/01 10:11:43 OK 3_commit_push.sql (2.62ms)23072026/10/01 10:11:43 goose: up to current file version: 32308--- PASS: TestReadProxyRangeRequest (0.45s)2309=== CONT TestReadProxy40423102026-10-01 10:11:43.767 UTC [1639] ERROR: relation "goose_db_version" does not exist at character 3623112026-10-01 10:11:43.767 UTC [1639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23122026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.43ms)23132026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)23142026/10/01 10:11:43 OK 20241026095416_initial_model.sql (11.59ms)23152026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.17ms)23162026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)23172026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.78ms)23182026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)23192026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.75ms)23202026/10/01 10:11:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"23212026/10/01 10:11:43 WARN mTLS auth: bound subjects configured but subject DN unavailable23222026/10/01 10:11:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2323--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.46s)2324=== CONT TestIsValidCachePath23252026/10/01 10:11:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45311/oidc2326=== RUN TestIsValidCachePath/narinfo2327=== PAUSE TestIsValidCachePath/narinfo2328=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2329=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2330=== RUN TestIsValidCachePath/nar_zst2331=== PAUSE TestIsValidCachePath/nar_zst2332=== RUN TestIsValidCachePath/nar_xz2333=== PAUSE TestIsValidCachePath/nar_xz2334=== RUN TestIsValidCachePath/nar_bz22335=== PAUSE TestIsValidCachePath/nar_bz22336=== RUN TestIsValidCachePath/nar_uncompressed2337=== PAUSE TestIsValidCachePath/nar_uncompressed2338=== RUN TestIsValidCachePath/ls2339=== PAUSE TestIsValidCachePath/ls2340=== RUN TestIsValidCachePath/log2341=== PAUSE TestIsValidCachePath/log2342=== RUN TestIsValidCachePath/realisation2343=== PAUSE TestIsValidCachePath/realisation2344=== RUN TestIsValidCachePath/nix-cache-info2345=== PAUSE TestIsValidCachePath/nix-cache-info2346=== RUN TestIsValidCachePath/index.html2347=== PAUSE TestIsValidCachePath/index.html2348=== RUN TestIsValidCachePath/traversal_parent2349=== PAUSE TestIsValidCachePath/traversal_parent2350=== RUN TestIsValidCachePath/traversal_in_middle2351=== PAUSE TestIsValidCachePath/traversal_in_middle2352=== RUN TestIsValidCachePath/invalid_char_e2353=== PAUSE TestIsValidCachePath/invalid_char_e2354=== RUN TestIsValidCachePath/invalid_char_u2355=== PAUSE TestIsValidCachePath/invalid_char_u2356=== RUN TestIsValidCachePath/random_path2357=== PAUSE TestIsValidCachePath/random_path2358=== RUN TestIsValidCachePath/empty2359=== PAUSE TestIsValidCachePath/empty2360=== RUN TestIsValidCachePath/leading_slash2361=== PAUSE TestIsValidCachePath/leading_slash2362=== RUN TestIsValidCachePath/wrong_extension2363=== PAUSE TestIsValidCachePath/wrong_extension2364=== RUN TestIsValidCachePath/short_hash2365=== PAUSE TestIsValidCachePath/short_hash2366=== CONT TestReadProxyNarStreaming23672026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (11.17ms)23682026/10/01 10:11:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23692026/10/01 10:11:43 OK 20260905000000_add_claims.sql (12.63ms)23702026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (12.83ms)23712026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.09ms)23722026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.26ms)23732026/10/01 10:11:43 OK 20260905000000_add_claims.sql (4.26ms)23742026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)23752026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.49ms)23762026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000023772026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.86ms)23782026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.08ms)23792026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.05ms)23802026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.58ms)23812026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000023822026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.22ms)23832026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.72ms)23842026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.02ms)23852026-10-01 10:11:43.810 UTC [1830] ERROR: relation "goose_db_version" does not exist at character 3623862026-10-01 10:11:43.810 UTC [1830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23872026/10/01 10:11:43 OK 3_commit_push.sql (2.06ms)23882026/10/01 10:11:43 goose: up to current file version: 323892026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.41ms)23902026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000023912026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.68ms)23922026/10/01 10:11:43 OK 3_commit_push.sql (1.25ms)23932026/10/01 10:11:43 goose: up to current file version: 323942026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.94ms)2395--- PASS: TestService_ReadScope_PublicByDefault (0.46s)2396=== CONT TestParseSingleRange2397=== RUN TestParseSingleRange/none2398=== PAUSE TestParseSingleRange/none2399=== RUN TestParseSingleRange/unknown_unit2400=== PAUSE TestParseSingleRange/unknown_unit2401=== RUN TestParseSingleRange/multi-range_ignored2402=== PAUSE TestParseSingleRange/multi-range_ignored2403=== RUN TestParseSingleRange/malformed_no_dash2404=== PAUSE TestParseSingleRange/malformed_no_dash2405=== RUN TestParseSingleRange/malformed_both_empty2406=== PAUSE TestParseSingleRange/malformed_both_empty2407=== RUN TestParseSingleRange/malformed_end_before_start2408=== PAUSE TestParseSingleRange/malformed_end_before_start2409=== RUN TestParseSingleRange/closed2410=== PAUSE TestParseSingleRange/closed2411=== RUN TestParseSingleRange/open-ended2412=== PAUSE TestParseSingleRange/open-ended2413=== RUN TestParseSingleRange/end_clamped_to_size2414=== PAUSE TestParseSingleRange/end_clamped_to_size24152026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.77ms)2416=== RUN TestParseSingleRange/suffix2417=== PAUSE TestParseSingleRange/suffix2418=== RUN TestParseSingleRange/suffix_exceeds_size2419=== PAUSE TestParseSingleRange/suffix_exceeds_size2420=== RUN TestParseSingleRange/single_byte2421=== PAUSE TestParseSingleRange/single_byte2422=== RUN TestParseSingleRange/start_past_EOF2423=== PAUSE TestParseSingleRange/start_past_EOF2424=== RUN TestParseSingleRange/start_far_past_EOF2425=== PAUSE TestParseSingleRange/start_far_past_EOF2426=== CONT TestPresentNotReportedWhileGCDeletesClosure24272026-10-01 10:11:43.816 UTC [1831] ERROR: relation "goose_db_version" does not exist at character 3624282026-10-01 10:11:43.816 UTC [1831] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24292026/10/01 10:11:43 OK 3_commit_push.sql (2.12ms)24302026/10/01 10:11:43 goose: up to current file version: 32431=== NAME TestClientCADerivations2432 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2433 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2434 error: binary cache 's3://bucket46?endpoint=http://localhost:37961®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations257425860/001/store'2435 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 124362026/10/01 10:11:43 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0Ljg3MTM4YzljLTRhNDItNGM3ZS1iYWIyLWZjMTg5ODE0ZTI5MXgxNzkwODQ5NTAzMjM5MTE2NDYx parts=1224372026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures24382026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.99ms)24392026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)2440--- PASS: TestClientCADerivations (0.92s)2441=== CONT TestReadProxyNarinfoAlreadyDecompressed2442--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.15s)2443=== CONT TestProxyHeadersOnlyTrustedOnSocket24442026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.73ms)24452026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.5ms)24462026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)24472026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)24482026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.81ms)24492026/10/01 10:11:43 OK 20260905000000_add_claims.sql (4.57ms)24502026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)2451--- PASS: TestService_ReadAuthMiddleware (0.47s)2452=== CONT TestPresentReportsOnlyClosureRoots24532026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.58ms)24542026-10-01 10:11:43.843 UTC [1838] ERROR: relation "goose_db_version" does not exist at character 3624552026-10-01 10:11:43.843 UTC [1838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24562026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.86ms)24572026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000024582026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.54ms)24592026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.01ms)24602026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.66ms)24612026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.85ms)24622026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (3.48ms)24632026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000024642026/10/01 10:11:43 OK 3_commit_push.sql (1.78ms)24652026/10/01 10:11:43 goose: up to current file version: 324662026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.62ms)24672026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.66ms)24682026/10/01 10:11:43 OK 3_commit_push.sql (1.89ms)24692026/10/01 10:11:43 goose: up to current file version: 324702026/10/01 10:11:43 OK 20241026095416_initial_model.sql (10.42ms)24712026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)2472=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2473=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2474=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2475=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2476=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2477=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2478=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2479=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2480=== CONT TestNARDeduplicationMetadataUploadBug24812026/10/01 10:11:43 OK 20251218171726_add_pins.sql (12.28ms)24822026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (8.99ms)24832026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.58ms)24842026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.17ms)24852026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (3.74ms)24862026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000024872026/10/01 10:11:43 OK 1_commit_pending_closure.sql (3.38ms)24882026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures24892026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.51ms)24902026/10/01 10:11:43 OK 3_commit_push.sql (1.4ms)24912026/10/01 10:11:43 goose: up to current file version: 324922026/10/01 10:11:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24932026-10-01 10:11:43.909 UTC [1843] ERROR: relation "goose_db_version" does not exist at character 3624942026-10-01 10:11:43.909 UTC [1843] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24952026-10-01 10:11:43.910 UTC [1844] ERROR: relation "goose_db_version" does not exist at character 3624962026-10-01 10:11:43.910 UTC [1844] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2497--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.46s)2498=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info24992026/10/01 10:11:43 INFO Received uploads request method=POST path=/2500=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25012026/10/01 10:11:43 INFO Received request for more parts method=POST path=/2502=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key25032026/10/01 10:11:43 INFO Received complete multipart upload request method=POST path=/2504=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25052026/10/01 10:11:43 INFO Received uploads request method=POST path=/2506--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2507 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2508 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2509 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2510 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2511=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2512=== RUN TestService_RequireScope_OIDC/builder_may_write2513=== PAUSE TestService_RequireScope_OIDC/builder_may_write2514=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2515=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2516=== RUN TestService_RequireScope_OIDC/ops_may_admin2517=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2518=== RUN TestService_RequireScope_OIDC/ops_may_not_write2519=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2520=== RUN TestService_RequireScope_OIDC/reader_may_not_write2521=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2522=== RUN TestService_RequireScope_OIDC/static_token_may_admin2523=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2524=== RUN TestService_RequireScope_OIDC/static_token_may_write2525=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2526=== RUN TestService_RequireScope_OIDC/reader_may_read2527=== PAUSE TestService_RequireScope_OIDC/reader_may_read2528=== RUN TestService_RequireScope_OIDC/writer_implies_read2529=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2530=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2531=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2532=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check25332026/10/01 10:11:43 OK 20241026095416_initial_model.sql (17.69ms)25342026/10/01 10:11:43 OK 20241026095416_initial_model.sql (19.15ms)25352026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)25362026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)25372026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.13ms)25382026-10-01 10:11:43.943 UTC [1848] ERROR: relation "goose_db_version" does not exist at character 3625392026-10-01 10:11:43.943 UTC [1848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25402026/10/01 10:11:43 OK 20251218171726_add_pins.sql (5.51ms)25412026/10/01 10:11:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LmI2OTk4MGMxLTc3YzYtNGNiOC04YzU3LTllYjUxYWQwMDQ1NHgxNzkwODQ5NTAzMzI0MDIzOTYx parts=1225422026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures25432026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)25442026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)25452026-10-01 10:11:43.951 UTC [1850] ERROR: relation "goose_db_version" does not exist at character 3625462026-10-01 10:11:43.951 UTC [1850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25472026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.8ms)25482026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.78ms)25492026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.7ms)25502026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures25512026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.44ms)25522026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.51ms)25532026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000025542026-10-01 10:11:43.957 UTC [1851] ERROR: relation "goose_db_version" does not exist at character 3625552026-10-01 10:11:43.957 UTC [1851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25562026-10-01 10:11:43.957 UTC [1852] ERROR: relation "goose_db_version" does not exist at character 3625572026-10-01 10:11:43.957 UTC [1852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25582026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.46ms)25592026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.99ms)25602026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000025612026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.8ms)25622026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.59ms)25632026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.46ms)25642026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)25652026/10/01 10:11:43 OK 3_commit_push.sql (2.11ms)25662026/10/01 10:11:43 goose: up to current file version: 325672026/10/01 10:11:43 OK 2_object_stats_trigger.sql (2.24ms)25682026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.43ms)25692026/10/01 10:11:43 OK 3_commit_push.sql (2.04ms)25702026/10/01 10:11:43 goose: up to current file version: 325712026/10/01 10:11:43 OK 20241026095416_initial_model.sql (10.89ms)25722026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)25732026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)25742026-10-01 10:11:43.971 UTC [1853] ERROR: relation "goose_db_version" does not exist at character 3625752026-10-01 10:11:43.971 UTC [1853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25762026/10/01 10:11:43 OK 20260905000000_add_claims.sql (3.84ms)25772026/10/01 10:11:43 OK 20251218171726_add_pins.sql (4.35ms)25782026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.56ms)25792026/10/01 10:11:43 OK 20241026095416_initial_model.sql (9.44ms)25802026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.98ms)25812026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)25822026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)25832026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)2584--- PASS: TestObjectStatsTrigger (0.47s)2585=== CONT TestIsValidUploadKey/narinfo2586=== CONT TestIsValidUploadKey/unknown_type2587=== CONT TestIsValidUploadKey/empty_key2588=== CONT TestIsValidUploadKey/absolute2589=== CONT TestIsValidUploadKey/build_log_equals2590=== CONT TestIsValidUploadKey/build_log_question_mark2591=== CONT TestIsValidUploadKey/build_log_plus_in_name2592=== CONT TestIsValidUploadKey/build_log_home-manager_file2593=== CONT TestIsValidUploadKey/realisation2594=== CONT TestIsValidUploadKey/build_log25952026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.91ms)2596=== CONT TestIsValidUploadKey/listing25972026/10/01 10:11:43 goose: successfully migrated database to version: 202609231200002598=== CONT TestIsValidUploadKey/traversal_nar2599=== CONT TestIsValidUploadKey/nar_plain2600=== CONT TestIsValidUploadKey/traversal2601=== CONT TestIsValidUploadKey/nar_xz2602=== CONT TestIsValidUploadKey/nar_zst2603=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2604=== CONT TestIsValidUploadKey/nix-cache-info2605=== CONT TestIsValidUploadKey/realisation_plus_in_output2606=== CONT TestIsValidUploadKey/index.html2607=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2608=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2609--- PASS: TestIsValidUploadKey (0.19s)2610 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2611 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2612 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2613 --- PASS: TestIsValidUploadKey/absolute (0.00s)2614 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2615 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2616 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2617 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2618 --- PASS: TestIsValidUploadKey/realisation (0.00s)2619 --- PASS: TestIsValidUploadKey/build_log (0.00s)2620 --- PASS: TestIsValidUploadKey/listing (0.00s)2621 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2622 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2623 --- PASS: TestIsValidUploadKey/traversal (0.00s)2624 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2625 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2626 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2627 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2628 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2629 --- PASS: TestIsValidUploadKey/index.html (0.00s)2630 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2631 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2632=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure26332026/10/01 10:11:43 INFO Received uploads request method=POST path=/26342026/10/01 10:11:43 OK 20251218171726_add_pins.sql (2.68ms)26352026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.44ms)26362026/10/01 10:11:43 OK 20260905000000_add_claims.sql (2.81ms)26372026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.6ms)26382026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (1.9ms)26392026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.66ms)26402026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)26412026/10/01 10:11:43 OK 3_commit_push.sql (1.36ms)26422026/10/01 10:11:43 goose: up to current file version: 326432026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)26442026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.31ms)26452026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000026462026/10/01 10:11:43 OK 20241026095416_initial_model.sql (8.6ms)26472026/10/01 10:11:43 INFO Received uploads request method=POST path=/api/pending_closures26482026-10-01 10:11:43.988 UTC [1854] ERROR: relation "goose_db_version" does not exist at character 3626492026-10-01 10:11:43.988 UTC [1854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26502026/10/01 10:11:43 OK 20260905000000_add_claims.sql (4.61ms)26512026/10/01 10:11:43 OK 1_commit_pending_closure.sql (4.22ms)26522026/10/01 10:11:43 OK 20260905000000_add_claims.sql (4.91ms)26532026/10/01 10:11:43 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)26542026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (2.59ms)26552026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.96ms)26562026/10/01 10:11:43 OK 20260920000000_drop_claims.sql (3.72ms)26572026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (2.46ms)26582026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000026592026/10/01 10:11:43 OK 20251218171726_add_pins.sql (3.83ms)26602026/10/01 10:11:43 OK 3_commit_push.sql (1.97ms)26612026/10/01 10:11:43 goose: up to current file version: 326622026/10/01 10:11:43 OK 20260923120000_add_pushes.sql (1.6ms)26632026/10/01 10:11:43 goose: successfully migrated database to version: 2026092312000026642026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.3ms)26652026/10/01 10:11:43 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)26662026/10/01 10:11:43 OK 1_commit_pending_closure.sql (2.19ms)26672026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.34ms)26682026/10/01 10:11:43 OK 2_object_stats_trigger.sql (1.36ms)26692026/10/01 10:11:44 OK 3_commit_push.sql (1.87ms)26702026/10/01 10:11:44 goose: up to current file version: 326712026/10/01 10:11:44 OK 3_commit_push.sql (1.24ms)26722026/10/01 10:11:44 goose: up to current file version: 326732026/10/01 10:11:44 OK 20260905000000_add_claims.sql (3.31ms)26742026/10/01 10:11:44 INFO Received uploads request method=POST path=/api/pending_closures26752026/10/01 10:11:44 OK 20260920000000_drop_claims.sql (3.15ms)26762026/10/01 10:11:44 OK 20241026095416_initial_model.sql (9.14ms)26772026/10/01 10:11:44 OK 20260923120000_add_pushes.sql (2.21ms)26782026/10/01 10:11:44 goose: successfully migrated database to version: 2026092312000026792026/10/01 10:11:44 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)26802026/10/01 10:11:44 OK 1_commit_pending_closure.sql (2.3ms)26812026/10/01 10:11:44 OK 20251218171726_add_pins.sql (3.09ms)26822026/10/01 10:11:44 OK 2_object_stats_trigger.sql (1.38ms)26832026/10/01 10:11:44 OK 3_commit_push.sql (1.54ms)26842026/10/01 10:11:44 goose: up to current file version: 326852026/10/01 10:11:44 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)26862026/10/01 10:11:44 INFO Received cleanup request method=DELETE path=/api/pending_closures26872026/10/01 10:11:44 OK 20260905000000_add_claims.sql (2.84ms)26882026/10/01 10:11:44 OK 20260920000000_drop_claims.sql (9.22ms)26892026/10/01 10:11:44 OK 20260923120000_add_pushes.sql (1.82ms)26902026/10/01 10:11:44 goose: successfully migrated database to version: 2026092312000026912026/10/01 10:11:44 OK 1_commit_pending_closure.sql (2.01ms)26922026/10/01 10:11:44 OK 2_object_stats_trigger.sql (703.39µs)26932026/10/01 10:11:44 OK 3_commit_push.sql (644.39µs)26942026/10/01 10:11:44 goose: up to current file version: 326952026-10-01 10:11:44.036 UTC [1855] ERROR: relation "goose_db_version" does not exist at character 3626962026-10-01 10:11:44.036 UTC [1855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26972026-10-01 10:11:44.040 UTC [1856] ERROR: relation "goose_db_version" does not exist at character 3626982026-10-01 10:11:44.040 UTC [1856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26992026/10/01 10:11:44 OK 20241026095416_initial_model.sql (8.02ms)27002026/10/01 10:11:44 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)27012026/10/01 10:11:44 OK 20241026095416_initial_model.sql (7.68ms)27022026/10/01 10:11:44 OK 20251218171726_add_pins.sql (2.06ms)27032026/10/01 10:11:44 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)27042026/10/01 10:11:44 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)27052026/10/01 10:11:44 OK 20251218171726_add_pins.sql (2.55ms)27062026/10/01 10:11:44 OK 20260905000000_add_claims.sql (2.23ms)27072026/10/01 10:11:44 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)27082026/10/01 10:11:44 OK 20260920000000_drop_claims.sql (1.41ms)27092026/10/01 10:11:44 OK 20260923120000_add_pushes.sql (1.6ms)27102026/10/01 10:11:44 goose: successfully migrated database to version: 2026092312000027112026/10/01 10:11:44 OK 20260905000000_add_claims.sql (2.3ms)27122026/10/01 10:11:44 OK 1_commit_pending_closure.sql (1.56ms)27132026/10/01 10:11:44 OK 20260920000000_drop_claims.sql (1.54ms)27142026/10/01 10:11:44 OK 2_object_stats_trigger.sql (719.05µs)27152026/10/01 10:11:44 OK 20260923120000_add_pushes.sql (1.21ms)27162026/10/01 10:11:44 goose: successfully migrated database to version: 2026092312000027172026/10/01 10:11:44 OK 3_commit_push.sql (845.87µs)27182026/10/01 10:11:44 goose: up to current file version: 327192026/10/01 10:11:44 OK 1_commit_pending_closure.sql (1.88ms)27202026/10/01 10:11:44 OK 2_object_stats_trigger.sql (695.74µs)27212026/10/01 10:11:44 OK 3_commit_push.sql (708.89µs)27222026/10/01 10:11:44 goose: up to current file version: 32723--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)2724=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts27252026/10/01 10:11:44 INFO Received request for more parts method=POST path=/27262026/10/01 10:11:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"27272026/10/01 10:11:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2728--- PASS: TestService_NativeMTLS (0.48s)2729=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart27302026/10/01 10:11:44 INFO Received complete multipart upload request method=POST path=/27312026/10/01 10:11:44 INFO Received uploads request method=POST path=/api/pending_closures2732=== CONT TestResolveDBConnectionString/flag_wins2733=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2734=== CONT TestResolveDBConnectionString/nothing_configured2735=== CONT TestResolveDBConnectionString/missing_file_is_an_error2736=== CONT TestResolveDBConnectionString/file_when_flag_empty2737=== CONT TestProxyWriteTimeout/narinfo2738=== CONT TestProxyWriteTimeout/10_GiB_nar2739=== CONT TestProxyWriteTimeout/unknown_size2740=== CONT TestProxyWriteTimeout/1_GiB_nar2741--- PASS: TestProxyWriteTimeout (0.00s)2742 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2743 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2744 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2745 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2746=== CONT TestCacheConfigHandler/full_config,_no_issuer2747=== CONT TestCacheConfigHandler/no_signing_keys2748--- PASS: TestResolveDBConnectionString (0.00s)2749 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2750 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2751 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2752 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2753 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2754=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2755=== CONT TestCacheConfigHandler/no_cache_url_configured2756=== CONT TestClientErrorHandling/InvalidStorePath2757--- PASS: TestCacheConfigHandler (0.00s)2758 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2759 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2760 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2761 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2762--- PASS: TestReadProxyNarinfo (0.47s)2763=== CONT TestClientErrorHandling/ServerNotAvailable2764=== CONT TestClientErrorHandling/InvalidAuthToken2765--- PASS: TestReadProxyInvalidPath (0.48s)2766=== CONT TestPush_RejectsBadRequests/no_roots27672026/10/01 10:11:44 INFO Received push request method=POST path=/api/pushes2768=== CONT TestPush_RejectsBadRequests/bad_root27692026/10/01 10:11:44 INFO Received push request method=POST path=/api/pushes2770=== CONT TestPush_RejectsBadRequests/root_not_in_objects27712026/10/01 10:11:44 INFO Received push request method=POST path=/api/pushes2772=== CONT TestPush_RejectsBadRequests/no_objects27732026/10/01 10:11:44 INFO Received push request method=POST path=/api/pushes2774=== CONT TestServerTLSConfig/no_client_CA2775=== CONT TestServerTLSConfig/missing_CA_file2776--- PASS: TestPush_RejectsBadRequests (0.54s)2777 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2778 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2779 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2780 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2781=== CONT TestServerTLSConfig/not_a_PEM_file2782--- PASS: TestServerTLSConfig (0.00s)2783 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2784 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2785 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2786=== CONT TestIsValidCachePath/narinfo2787=== CONT TestIsValidCachePath/index.html2788=== CONT TestIsValidCachePath/invalid_char_u2789=== CONT TestIsValidCachePath/invalid_char_e2790=== CONT TestIsValidCachePath/random_path2791=== CONT TestIsValidCachePath/traversal_in_middle2792=== CONT TestIsValidCachePath/short_hash2793=== CONT TestIsValidCachePath/traversal_parent2794=== CONT TestIsValidCachePath/wrong_extension2795=== CONT TestIsValidCachePath/empty2796=== CONT TestIsValidCachePath/leading_slash2797=== CONT TestIsValidCachePath/nar_xz2798=== CONT TestIsValidCachePath/nar_zst2799=== CONT TestIsValidCachePath/nar_bz22800=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2801=== CONT TestIsValidCachePath/realisation2802=== CONT TestIsValidCachePath/nar_uncompressed2803=== CONT TestIsValidCachePath/nix-cache-info2804=== CONT TestIsValidCachePath/log2805=== CONT TestIsValidCachePath/ls2806--- PASS: TestIsValidCachePath (0.00s)2807 --- PASS: TestIsValidCachePath/narinfo (0.00s)2808 --- PASS: TestIsValidCachePath/index.html (0.00s)2809 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2810 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2811 --- PASS: TestIsValidCachePath/random_path (0.00s)2812 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2813 --- PASS: TestIsValidCachePath/short_hash (0.00s)2814 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2815 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2816 --- PASS: TestIsValidCachePath/empty (0.00s)2817 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2818 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2819 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2820 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2821 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2822 --- PASS: TestIsValidCachePath/realisation (0.00s)2823 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2824 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2825 --- PASS: TestIsValidCachePath/log (0.00s)2826 --- PASS: TestIsValidCachePath/ls (0.00s)2827=== CONT TestParseSingleRange/none2828=== CONT TestParseSingleRange/open-ended2829=== CONT TestParseSingleRange/start_far_past_EOF2830=== CONT TestParseSingleRange/start_past_EOF2831=== CONT TestParseSingleRange/single_byte2832=== CONT TestParseSingleRange/suffix_exceeds_size2833=== CONT TestParseSingleRange/suffix2834=== CONT TestParseSingleRange/end_clamped_to_size2835=== CONT TestParseSingleRange/malformed_both_empty2836=== CONT TestParseSingleRange/closed2837=== CONT TestParseSingleRange/malformed_end_before_start2838=== CONT TestParseSingleRange/malformed_no_dash2839=== CONT TestParseSingleRange/multi-range_ignored2840=== CONT TestParseSingleRange/unknown_unit2841--- PASS: TestParseSingleRange (0.00s)2842 --- PASS: TestParseSingleRange/none (0.00s)2843 --- PASS: TestParseSingleRange/open-ended (0.00s)2844 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2845 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2846 --- PASS: TestParseSingleRange/single_byte (0.00s)2847 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2848 --- PASS: TestParseSingleRange/suffix (0.00s)2849 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2850 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2851 --- PASS: TestParseSingleRange/closed (0.00s)2852 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2853 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2854 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2855 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2856=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2857=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected28582026/10/01 10:11:44 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]2859=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2860=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected28612026/10/01 10:11:44 WARN Authentication failed token_preview=eyJhbGciOi...Td5td_GiOw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2862=== CONT TestService_RequireScope_OIDC/builder_may_write2863=== CONT TestService_RequireScope_OIDC/static_token_may_admin2864=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2865=== CONT TestService_RequireScope_OIDC/writer_implies_read2866--- PASS: TestService_AuthMiddleware_OIDC (0.55s)2867 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2868 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2869 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2870 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2871=== CONT TestService_RequireScope_OIDC/reader_may_read2872=== CONT TestService_RequireScope_OIDC/static_token_may_write2873=== CONT TestService_RequireScope_OIDC/reader_may_not_write2874=== CONT TestService_RequireScope_OIDC/ops_may_not_write2875=== CONT TestService_RequireScope_OIDC/ops_may_admin2876=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2877--- PASS: TestService_RequireScope_OIDC (0.55s)2878 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2879 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2880 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2881 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2882 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2883 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2884 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2885 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2886 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2887 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2888--- PASS: TestMetricsInventory (0.51s)28892026/10/01 10:11:44 INFO Received cleanup request method=DELETE path=/api/pending_closures28902026-10-01 10:11:44.244 UTC [1896] ERROR: relation "goose_db_version" does not exist at character 3628912026-10-01 10:11:44.244 UTC [1896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28922026/10/01 10:11:44 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket70/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""28932026/10/01 10:11:44 INFO Aborted multipart uploads count=0 kept=128942026/10/01 10:11:44 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/present28952026/10/01 10:11:44 INFO Received cleanup request method=DELETE path=/api/pending_closures28962026/10/01 10:11:44 INFO Aborted multipart uploads count=1 kept=02897--- PASS: TestMultipartCleanup (0.62s)28982026/10/01 10:11:44 OK 20241026095416_initial_model.sql (7.06ms)28992026/10/01 10:11:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29002026/10/01 10:11:44 WARN Refused reserved pin name=worker-x86_64-linux29012026/10/01 10:11:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29022026/10/01 10:11:44 INFO Received create pin request method=POST path=/api/pins/my-app29032026/10/01 10:11:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29042026/10/01 10:11:44 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)2905--- PASS: TestCreatePin_ReservedPins (0.59s)29062026/10/01 10:11:44 OK 20251218171726_add_pins.sql (2.25ms)29072026/10/01 10:11:44 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)29082026/10/01 10:11:44 OK 20260905000000_add_claims.sql (2.6ms)29092026-10-01 10:11:44.268 UTC [1897] ERROR: relation "goose_db_version" does not exist at character 3629102026-10-01 10:11:44.268 UTC [1897] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29112026/10/01 10:11:44 OK 20260920000000_drop_claims.sql (1.66ms)29122026/10/01 10:11:44 OK 20260923120000_add_pushes.sql (1.19ms)29132026/10/01 10:11:44 goose: successfully migrated database to version: 2026092312000029142026/10/01 10:11:44 OK 1_commit_pending_closure.sql (1.41ms)29152026/10/01 10:11:44 OK 2_object_stats_trigger.sql (716.21µs)29162026/10/01 10:11:44 OK 3_commit_push.sql (605.43µs)29172026/10/01 10:11:44 goose: up to current file version: 329182026/10/01 10:11:44 OK 20241026095416_initial_model.sql (7.12ms)29192026/10/01 10:11:44 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)29202026/10/01 10:11:44 OK 20251218171726_add_pins.sql (2.18ms)29212026/10/01 10:11:44 OK 20260628120000_add_object_size_and_stats.sql (2.23ms)29222026/10/01 10:11:44 OK 20260905000000_add_claims.sql (2.19ms)29232026/10/01 10:11:44 OK 20260920000000_drop_claims.sql (1.54ms)29242026/10/01 10:11:44 OK 20260923120000_add_pushes.sql (1.16ms)29252026/10/01 10:11:44 goose: successfully migrated database to version: 2026092312000029262026/10/01 10:11:44 OK 1_commit_pending_closure.sql (1.52ms)29272026/10/01 10:11:44 OK 2_object_stats_trigger.sql (796.76µs)29282026/10/01 10:11:44 OK 3_commit_push.sql (689.01µs)29292026/10/01 10:11:44 goose: up to current file version: 32930--- PASS: TestReadProxy404 (0.54s)2931--- PASS: TestReadProxyNarStreaming (0.52s)29322026/10/01 10:11:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.650408ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2933=== NAME TestOrphanedObjectsGC2934 orphaned_objects_gc_test.go:290: GC Test Summary:2935 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2936 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2937 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2938 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2939 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2940--- PASS: TestOrphanedObjectsGC (0.82s)2941--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.54s)29422026/10/01 10:11:44 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3987931513/001/proxy.sock29432026/10/01 10:11:44 INFO Starting HTTP server address=127.0.0.1:4257329442026/10/01 10:11:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"29452026/10/01 10:11:44 INFO Shutdown signal received, draining in-flight requests timeout=10s2946--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.56s)2947--- PASS: TestPresentReportsOnlyClosureRoots (0.58s)29482026/10/01 10:11:44 INFO Received uploads request method=POST path=/api/pending_closures29492026/10/01 10:11:44 INFO Aborted multipart uploads count=0 kept=02950=== NAME TestNARDeduplicationMetadataUploadBug2951 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1123363143/001/store/nyc1f4zgy20kcvwcrj8q183zfjqksp1j-file1.txt29522026/10/01 10:11:44 WARN Force mode enabled - objects will be deleted immediately without grace period29532026/10/01 10:11:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029542026/10/01 10:11:44 INFO Vacuumed table table=pending_closures29552026/10/01 10:11:44 INFO Vacuumed table table=pending_objects29562026/10/01 10:11:44 INFO Vacuumed table table=multipart_uploads29572026/10/01 10:11:44 INFO Vacuumed table table=closures29582026/10/01 10:11:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete29592026/10/01 10:11:44 INFO Received uploads request method=POST path=/api/pending_closures29602026/10/01 10:11:44 INFO Vacuumed table table=objects29612026/10/01 10:11:44 INFO Aborted multipart uploads count=0 kept=029622026/10/01 10:11:44 WARN Force mode enabled - objects will be deleted immediately without grace period29632026/10/01 10:11:44 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LmMyMmVkYWQ5LTRkYTUtNGM5Ny05Njc3LTVlYmZkYmJlYTliNXgxNzkwODQ5NTAzOTYwMjY3Nzg5 error="Get \"http://127.0.0.1:1/bucket42/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"29642026/10/01 10:11:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTM0NzI0Y2YtMTI4YS00OGI3LWIxNzYtN2Y0YzdkY2MxMDU0LmNhMDkzMTk2LWMwMjUtNDdiYy04NDAwLWU5YmYwYWI0NTI0YXgxNzkwODQ5NTAzOTUwOTE0NTc5 parts=1229652026/10/01 10:11:44 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=029662026/10/01 10:11:44 INFO Received cleanup request method=DELETE path=/api/pending_closures29672026/10/01 10:11:44 INFO Vacuumed table table=pending_closures29682026/10/01 10:11:44 INFO Vacuumed table table=pending_objects29692026/10/01 10:11:44 INFO Vacuumed table table=multipart_uploads29702026/10/01 10:11:44 INFO Aborted multipart uploads count=1 kept=029712026/10/01 10:11:44 INFO Vacuumed table table=closures29722026/10/01 10:11:44 INFO Vacuumed table table=objects2973--- PASS: TestRedundantMultipartUpload (1.73s)2974--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2975 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.60s)2976 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.61s)29772026/10/01 10:11:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.266469ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29782026/10/01 10:11:44 INFO Received push request method=POST path=/api/pushes29792026/10/01 10:11:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29802026/10/01 10:11:44 INFO Uploading nyc1f4zgy20kcvwcrj8q183zfjqksp1j-file1.txt (160B)29812026/10/01 10:11:44 WARN Failed to register uploaded object key=nyc1f4zgy20kcvwcrj8q183zfjqksp1j.ls error="server returned 404: 404 page not found\n"29822026/10/01 10:11:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29832026/10/01 10:11:44 INFO Signed narinfos id=1 count=129842026/10/01 10:11:44 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"29852026/10/01 10:11:44 INFO Uploading 1 narinfos29862026/10/01 10:11:44 INFO Received complete push request method=POST path=/api/pushes/1/complete29872026/10/01 10:11:44 WARN Failed to register uploaded object key=nyc1f4zgy20kcvwcrj8q183zfjqksp1j.narinfo error="server returned 404: 404 page not found\n"29882026/10/01 10:11:44 INFO Upload complete. (53ms)2989=== NAME TestNARDeduplicationMetadataUploadBug2990 metadata_upload_test.go:54: Retrieved narinfo from S3:2991 StorePath: /build/TestNARDeduplicationMetadataUploadBug1123363143/001/store/nyc1f4zgy20kcvwcrj8q183zfjqksp1j-file1.txt2992 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2993 Compression: zstd2994 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2995 NarSize: 1602996 References: 2997 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2998 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2999 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):3000 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}3001--- PASS: TestUploadHandlersRejectOversizedBody (0.26s)3002 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)3003 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)3004 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.79s)3005=== NAME TestNARDeduplicationMetadataUploadBug3006 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1123363143/001/store/azvmw3jiczy1iw6bjrxqgvd60zhyi64x-file2.txt30072026/10/01 10:11:44 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30082026/10/01 10:11:44 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"3009--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.02s)30102026/10/01 10:11:44 INFO Received push request method=POST path=/api/pushes30112026/10/01 10:11:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)30122026/10/01 10:11:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign30132026/10/01 10:11:44 INFO Signed narinfos id=2 count=130142026/10/01 10:11:44 WARN Failed to register uploaded object key=azvmw3jiczy1iw6bjrxqgvd60zhyi64x.ls error="server returned 404: 404 page not found\n"30152026/10/01 10:11:44 INFO Uploading 1 narinfos30162026/10/01 10:11:44 INFO Received complete push request method=POST path=/api/pushes/2/complete30172026/10/01 10:11:44 WARN Failed to register uploaded object key=azvmw3jiczy1iw6bjrxqgvd60zhyi64x.narinfo error="server returned 404: 404 page not found\n"30182026/10/01 10:11:44 INFO Upload complete. (50ms)3019=== NAME TestNARDeduplicationMetadataUploadBug3020 metadata_upload_test.go:76: Retrieved narinfo from S3:3021 StorePath: /build/TestNARDeduplicationMetadataUploadBug1123363143/001/store/azvmw3jiczy1iw6bjrxqgvd60zhyi64x-file2.txt3022 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst3023 Compression: zstd3024 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3025 NarSize: 1603026 References: 3027 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3028 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)3029 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):3030 {"version":1,"root":{"type":"regular","size":44}}3031--- PASS: TestNARDeduplicationMetadataUploadBug (1.00s)30322026/10/01 10:11:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=791.193661ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30332026/10/01 10:11:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=030342026/10/01 10:11:45 INFO Received create pin request method=POST path=/api/pins/myapp30352026/10/01 10:11:45 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3519866355/001/store/99xw70nh0s85bfr9gc94k63ri53n92mf-pinned-file.txt narinfo_key=99xw70nh0s85bfr9gc94k63ri53n92mf.narinfo30362026/10/01 10:11:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures30372026/10/01 10:11:45 INFO Garbage collection started30382026/10/01 10:11:45 INFO Aborted multipart uploads count=0 kept=030392026/10/01 10:11:45 WARN Force mode enabled - objects will be deleted immediately without grace period30402026/10/01 10:11:45 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=030412026/10/01 10:11:45 INFO Vacuumed table table=pending_closures30422026/10/01 10:11:45 INFO Vacuumed table table=pending_objects30432026/10/01 10:11:45 INFO Vacuumed table table=multipart_uploads30442026/10/01 10:11:45 INFO Vacuumed table table=closures30452026/10/01 10:11:45 INFO Vacuumed table table=objects30462026/10/01 10:11:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03047=== NAME TestClientIntegration3048 client_integration_test.go:323: Objects in database after GC:3049=== NAME TestOrphanedObjectsGCStressTest3050 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains3051=== NAME TestClientIntegration3052 client_integration_test.go:323: Successfully deleted all objects with GC --force3053--- PASS: TestClientIntegration (2.78s)3054=== NAME TestOrphanedObjectsGCStressTest3055 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion30562026/10/01 10:11:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.61787821s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3057 orphaned_objects_gc_test.go:509: Stress test completed successfully:3058 orphaned_objects_gc_test.go:510: - Active objects preserved: 203059 orphaned_objects_gc_test.go:511: - Objects deleted: 2103060 orphaned_objects_gc_test.go:512: - Total GC'd: 2103061--- PASS: TestOrphanedObjectsGCStressTest (2.40s)30622026/10/01 10:11:46 WARN Rate limiter enabled after throttle name=s3-test rate=530632026/10/01 10:11:46 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3064=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3065 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103066 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003067--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.36s)30682026/10/01 10:11:47 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-config3069=== NAME TestPinProtectsFromGC3070 client_integration_test.go:840: Pin successfully protected closure from garbage collection3071--- PASS: TestPinProtectsFromGC (4.91s)30722026/10/01 10:11:47 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.261928ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30732026/10/01 10:11:47 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.951109ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30742026/10/01 10:11:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=867.135684ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30752026/10/01 10:11:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.505298311s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30762026/10/01 10:11:50 INFO Aborted multipart uploads count=1 kept=030772026/10/01 10:11:50 INFO Received cleanup request method=DELETE path=/api/pending_closures30782026/10/01 10:11:50 INFO Aborted multipart uploads count=1 kept=03079--- PASS: TestPendingCleanupUsesOneCutoff (6.49s)30802026/10/01 10:11:50 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"30812026/10/01 10:11:50 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-config30822026/10/01 10:11:50 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.689036ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30832026/10/01 10:11:50 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.024906ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30842026/10/01 10:11:51 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=825.548145ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30852026/10/01 10:11:52 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.637083474s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30862026/10/01 10:11:53 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_closures30872026/10/01 10:11:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.392892ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30882026/10/01 10:11:54 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.447765ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30892026/10/01 10:11:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=804.199432ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30902026/10/01 10:11:55 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.482108286s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3091--- PASS: TestClientErrorHandling (0.00s)3092 --- PASS: TestClientErrorHandling/InvalidStorePath (0.42s)3093 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.68s)3094 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.60s)3095PASS3096{"timestamp":"2026-10-01T10:11:56.763481067Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53834","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(400)"}30972026-10-01 10:11:57.111 UTC [129] LOG: received smart shutdown request30982026-10-01 10:11:57.115 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 130992026-10-01 10:11:57.127 UTC [134] LOG: shutting down31002026-10-01 10:11:57.129 UTC [134] LOG: checkpoint starting: shutdown immediate31012026-10-01 10:11:58.121 UTC [134] LOG: checkpoint complete: wrote 10811 buffers (66.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.279 s, sync=0.672 s, total=0.994 s; sync files=28648, longest=0.009 s, average=0.001 s; distance=396553 kB, estimate=396553 kB; lsn=0/19AA8370, redo lsn=0/19AA837031022026-10-01 10:11:58.201 UTC [129] LOG: database system is shut down3103Running OIDC tests...3104=== RUN TestAudienceForIssuer3105=== PAUSE TestAudienceForIssuer3106=== RUN TestGlobMatch3107=== PAUSE TestGlobMatch3108=== RUN TestValidateToken_ValidToken3109=== PAUSE TestValidateToken_ValidToken3110=== RUN TestValidateToken_WrongAudience3111=== PAUSE TestValidateToken_WrongAudience3112=== RUN TestValidateToken_Expired3113=== PAUSE TestValidateToken_Expired3114=== RUN TestValidateToken_BoundClaimsMismatch3115=== PAUSE TestValidateToken_BoundClaimsMismatch3116=== RUN TestValidateToken_BoundSubjectMismatch3117=== PAUSE TestValidateToken_BoundSubjectMismatch3118=== RUN TestValidateToken_MultipleProviders3119=== PAUSE TestValidateToken_MultipleProviders3120=== RUN TestValidateToken_NoMatchingProvider3121=== PAUSE TestValidateToken_NoMatchingProvider3122=== RUN TestValidateToken_KubernetesServiceAccount3123=== PAUSE TestValidateToken_KubernetesServiceAccount3124=== RUN TestNewValidator_KubernetesRequiresCA3125=== PAUSE TestNewValidator_KubernetesRequiresCA3126=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3127=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3128=== RUN TestPins_ReservedForMatchingRule3129=== PAUSE TestPins_ReservedForMatchingRule3130=== RUN TestPins_TopLevelShorthand3131=== PAUSE TestPins_TopLevelShorthand3132=== RUN TestPins_ConfigValidation3133=== PAUSE TestPins_ConfigValidation3134=== RUN TestScopes_LegacyProviderDefaultsToWrite3135=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3136=== RUN TestScopes_Rules3137=== PAUSE TestScopes_Rules3138=== RUN TestScopes_ConfigValidation3139=== PAUSE TestScopes_ConfigValidation3140=== CONT TestAudienceForIssuer3141=== CONT TestValidateToken_KubernetesServiceAccount3142=== CONT TestValidateToken_BoundSubjectMismatch3143--- PASS: TestAudienceForIssuer (0.00s)3144=== CONT TestValidateToken_Expired3145=== CONT TestValidateToken_WrongAudience3146=== CONT TestValidateToken_ValidToken3147=== CONT TestGlobMatch3148=== RUN TestGlobMatch/foo_foo3149=== PAUSE TestGlobMatch/foo_foo3150=== CONT TestValidateToken_MultipleProviders3151=== CONT TestValidateToken_NoMatchingProvider3152=== CONT TestPins_ConfigValidation3153=== CONT TestScopes_ConfigValidation3154=== CONT TestScopes_Rules3155=== CONT TestScopes_LegacyProviderDefaultsToWrite3156=== CONT TestPins_ReservedForMatchingRule3157=== CONT TestPins_TopLevelShorthand3158=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3159=== CONT TestNewValidator_KubernetesRequiresCA3160=== CONT TestValidateToken_BoundClaimsMismatch3161=== RUN TestGlobMatch/foo_bar3162=== PAUSE TestGlobMatch/foo_bar3163=== RUN TestGlobMatch/*_3164=== PAUSE TestGlobMatch/*_3165=== RUN TestGlobMatch/*_anything3166=== PAUSE TestGlobMatch/*_anything3167=== RUN TestGlobMatch/foo*_foo3168=== PAUSE TestGlobMatch/foo*_foo3169=== RUN TestGlobMatch/foo*_foobar3170=== PAUSE TestGlobMatch/foo*_foobar3171=== RUN TestGlobMatch/foo*_bar3172=== PAUSE TestGlobMatch/foo*_bar3173=== RUN TestGlobMatch/*bar_bar3174=== PAUSE TestGlobMatch/*bar_bar3175=== RUN TestGlobMatch/*bar_foobar3176=== PAUSE TestGlobMatch/*bar_foobar3177=== RUN TestGlobMatch/*bar_foo3178=== PAUSE TestGlobMatch/*bar_foo3179=== RUN TestGlobMatch/foo*bar_foobar3180=== PAUSE TestGlobMatch/foo*bar_foobar3181=== RUN TestGlobMatch/foo*bar_foo123bar3182=== PAUSE TestGlobMatch/foo*bar_foo123bar3183=== RUN TestGlobMatch/foo*bar_foobarbaz3184=== PAUSE TestGlobMatch/foo*bar_foobarbaz3185=== RUN TestGlobMatch/*/*_foo/bar3186=== PAUSE TestGlobMatch/*/*_foo/bar3187=== RUN TestGlobMatch/*/*_foo3188=== PAUSE TestGlobMatch/*/*_foo3189=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3190=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3191=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03192=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03193=== RUN TestGlobMatch/refs/*/main_refs/heads/main3194=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3195=== RUN TestGlobMatch/fo?_foo3196=== PAUSE TestGlobMatch/fo?_foo3197=== RUN TestGlobMatch/fo?_fo3198=== PAUSE TestGlobMatch/fo?_fo3199=== RUN TestGlobMatch/fo?_fooo3200=== PAUSE TestGlobMatch/fo?_fooo3201=== RUN TestGlobMatch/?oo_foo3202=== PAUSE TestGlobMatch/?oo_foo3203=== RUN TestGlobMatch/?oo_boo3204=== PAUSE TestGlobMatch/?oo_boo3205=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3206=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3207=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3208=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3209=== CONT TestGlobMatch/foo_foo3210=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3211=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3212=== CONT TestGlobMatch/?oo_boo3213=== CONT TestGlobMatch/?oo_foo3214=== CONT TestGlobMatch/foo*bar_foobar3215=== CONT TestGlobMatch/*bar_foo3216=== CONT TestGlobMatch/*bar_foobar3217=== CONT TestGlobMatch/*bar_bar3218=== CONT TestGlobMatch/foo*_bar3219=== CONT TestGlobMatch/foo*_foobar3220=== CONT TestGlobMatch/foo*_foo3221=== CONT TestGlobMatch/*_anything3222=== CONT TestGlobMatch/*_3223=== CONT TestGlobMatch/foo_bar3224=== CONT TestGlobMatch/foo*bar_foo123bar3225=== CONT TestGlobMatch/fo?_fooo3226=== CONT TestGlobMatch/fo?_fo3227=== CONT TestGlobMatch/fo?_foo3228=== CONT TestGlobMatch/refs/*/main_refs/heads/main3229=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03230=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3231=== CONT TestGlobMatch/*/*_foo3232=== CONT TestGlobMatch/*/*_foo/bar3233=== CONT TestGlobMatch/foo*bar_foobarbaz3234--- PASS: TestGlobMatch (0.00s)3235 --- PASS: TestGlobMatch/foo_foo (0.00s)3236 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3237 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3238 --- PASS: TestGlobMatch/?oo_boo (0.00s)3239 --- PASS: TestGlobMatch/?oo_foo (0.00s)3240 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3241 --- PASS: TestGlobMatch/*bar_foo (0.00s)3242 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3243 --- PASS: TestGlobMatch/*bar_bar (0.00s)3244 --- PASS: TestGlobMatch/foo*_bar (0.00s)3245 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3246 --- PASS: TestGlobMatch/foo*_foo (0.00s)3247 --- PASS: TestGlobMatch/*_anything (0.00s)3248 --- PASS: TestGlobMatch/*_ (0.00s)3249 --- PASS: TestGlobMatch/foo_bar (0.00s)3250 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3251 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3252 --- PASS: TestGlobMatch/fo?_fo (0.00s)3253 --- PASS: TestGlobMatch/fo?_foo (0.00s)3254 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3255 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3256 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3257 --- PASS: TestGlobMatch/*/*_foo (0.00s)3258 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3259 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3260--- PASS: TestPins_ConfigValidation (0.00s)3261--- PASS: TestScopes_ConfigValidation (0.00s)32622026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38859/oidc3263--- PASS: TestValidateToken_ValidToken (0.04s)32642026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46575/oidc32652026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33795/oidc32662026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45013/oidc3267--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)32682026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37879/oidc3269--- PASS: TestValidateToken_WrongAudience (0.05s)3270--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)3271--- PASS: TestPins_TopLevelShorthand (0.04s)32722026/10/01 10:12:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4321732732026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45529/oidc3274--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)3275--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)32762026/10/01 10:12:00 http: TLS handshake error from 127.0.0.1:45288: remote error: tls: bad certificate3277--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)32782026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36187/oidc32792026/10/01 10:12:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12332802026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39035/oidc3281--- PASS: TestPins_ReservedForMatchingRule (0.10s)3282--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)3283--- PASS: TestScopes_Rules (0.10s)32842026/10/01 10:12:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41205/oidc3285--- PASS: TestValidateToken_NoMatchingProvider (0.14s)32862026/10/01 10:12:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35071/oidc32872026/10/01 10:12:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34307/oidc3288--- PASS: TestValidateToken_MultipleProviders (0.18s)32892026/10/01 10:12:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33621/oidc3290--- PASS: TestValidateToken_Expired (0.22s)3291PASS3292Running hook tests...3293=== RUN TestSendPathsEmpty3294=== PAUSE TestSendPathsEmpty3295=== RUN TestQueueEnqueueAndFetch3296=== PAUSE TestQueueEnqueueAndFetch3297=== RUN TestQueueDeduplication3298=== PAUSE TestQueueDeduplication3299=== RUN TestQueueRemove3300=== PAUSE TestQueueRemove3301=== RUN TestQueueFetchBatchLimit3302=== PAUSE TestQueueFetchBatchLimit3303=== RUN TestQueueRetryMovesToBack3304=== PAUSE TestQueueRetryMovesToBack3305=== RUN TestQueueFetchRemoveLifecycle3306=== PAUSE TestQueueFetchRemoveLifecycle3307=== RUN TestQueueConcurrentWriters3308=== PAUSE TestQueueConcurrentWriters3309=== RUN TestQueueRemoveLargeClosure3310=== PAUSE TestQueueRemoveLargeClosure3311=== RUN TestServerClientIntegration3312=== PAUSE TestServerClientIntegration3313=== RUN TestServerQueueError3314=== PAUSE TestServerQueueError3315=== RUN TestGetListenerSocketActivation3316 server_test.go:210: === RUN TestGetListenerSocketActivation3317 --- PASS: TestGetListenerSocketActivation (0.00s)3318 PASS3319 3320--- PASS: TestGetListenerSocketActivation (0.01s)3321=== RUN TestDrainIsolatesPoisonPath3322=== PAUSE TestDrainIsolatesPoisonPath3323=== RUN TestRunNotBlockedByPoisonHead3324=== PAUSE TestRunNotBlockedByPoisonHead3325=== RUN TestDrainGivesUpWhenServerDown3326=== PAUSE TestDrainGivesUpWhenServerDown3327=== RUN TestFailedPathPrunedByLaterClosure3328=== PAUSE TestFailedPathPrunedByLaterClosure3329=== RUN TestWorkerUploadsAndRemoves3330=== PAUSE TestWorkerUploadsAndRemoves3331=== RUN TestWorkerSkipsGCdPaths3332=== PAUSE TestWorkerSkipsGCdPaths3333=== RUN TestWorkerPrunesClosureDeps3334=== PAUSE TestWorkerPrunesClosureDeps3335=== RUN TestDrainTimeout3336=== PAUSE TestDrainTimeout3337=== CONT TestSendPathsEmpty3338=== CONT TestServerQueueError3339--- PASS: TestSendPathsEmpty (0.00s)3340=== CONT TestServerClientIntegration3341=== CONT TestQueueRemoveLargeClosure3342=== CONT TestQueueConcurrentWriters33432026/10/01 10:12:00 ERROR Failed to queue paths error="permission denied" count=13344=== CONT TestQueueFetchRemoveLifecycle3345=== CONT TestQueueRetryMovesToBack3346=== CONT TestQueueFetchBatchLimit3347--- PASS: TestServerQueueError (0.00s)3348=== CONT TestQueueRemove3349=== CONT TestQueueDeduplication3350=== CONT TestQueueEnqueueAndFetch3351=== CONT TestDrainGivesUpWhenServerDown3352=== CONT TestFailedPathPrunedByLaterClosure3353=== CONT TestWorkerPrunesClosureDeps3354=== CONT TestDrainTimeout3355=== CONT TestRunNotBlockedByPoisonHead3356=== CONT TestWorkerSkipsGCdPaths3357=== CONT TestDrainIsolatesPoisonPath3358=== CONT TestWorkerUploadsAndRemoves3359--- PASS: TestServerClientIntegration (0.00s)33602026/10/01 10:12:00 INFO Uploading batch count=133612026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=133622026/10/01 10:12:00 INFO Uploading batch count=433632026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=433642026/10/01 10:12:00 INFO Upload queue status pending=333652026/10/01 10:12:00 INFO Uploading batch count=233662026/10/01 10:12:00 INFO Uploading batch count=233672026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=233682026/10/01 10:12:00 INFO Upload queue status pending=233692026/10/01 10:12:00 INFO Upload queue status pending=23370--- PASS: TestQueueEnqueueAndFetch (0.02s)33712026/10/01 10:12:00 INFO Upload queue status pending=233722026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath898001676/002/bbb3373--- PASS: TestQueueFetchBatchLimit (0.02s)33742026/10/01 10:12:00 INFO Uploading batch count=133752026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3573329275/002/a33762026/10/01 10:12:00 INFO Uploading batch count=133772026/10/01 10:12:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1734777502/002/nonexistent3378--- PASS: TestQueueDeduplication (0.02s)33792026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=133802026/10/01 10:12:00 INFO Uploading batch count=233812026/10/01 10:12:00 INFO Uploading batch count=133822026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3573329275/002/b33832026/10/01 10:12:00 INFO Uploading batch count=13384--- PASS: TestQueueFetchRemoveLifecycle (0.02s)3385--- PASS: TestQueueRemove (0.02s)3386--- PASS: TestQueueRetryMovesToBack (0.02s)33872026/10/01 10:12:00 INFO Uploading batch count=133882026/10/01 10:12:00 INFO Uploading batch count=133892026/10/01 10:12:00 INFO Uploading batch count=233902026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=233912026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3573329275/002/c33922026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=133932026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3573329275/002/d33942026/10/01 10:12:00 INFO Uploading batch count=133952026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=133962026/10/01 10:12:00 INFO Uploading batch count=233972026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=233982026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3573329275/002/e3399--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)34002026/10/01 10:12:00 INFO Uploading batch count=134012026/10/01 10:12:00 ERROR Upload failed error="upload failed" count=134022026/10/01 10:12:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3573329275/002/f34032026/10/01 10:12:00 ERROR Drain finished with paths left in queue remaining=134042026/10/01 10:12:00 ERROR Drain finished with paths left in queue remaining=103405--- PASS: TestDrainIsolatesPoisonPath (0.03s)3406--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3407--- PASS: TestWorkerUploadsAndRemoves (0.04s)3408--- PASS: TestWorkerSkipsGCdPaths (0.04s)3409--- PASS: TestWorkerPrunesClosureDeps (0.04s)3410--- PASS: TestQueueRemoveLargeClosure (0.09s)34112026/10/01 10:12:00 ERROR Upload failed error="context deadline exceeded" count=234122026/10/01 10:12:00 ERROR Drain finished with paths left in queue remaining=43413--- PASS: TestDrainTimeout (0.22s)3414--- PASS: TestQueueConcurrentWriters (0.38s)34152026/10/01 10:12:01 INFO Uploading batch count=134162026/10/01 10:12:01 INFO Uploading batch count=134172026/10/01 10:12:01 INFO Uploading batch count=134182026/10/01 10:12:01 ERROR Upload failed error="upload failed" count=134192026/10/01 10:12:01 INFO Uploading batch count=134202026/10/01 10:12:01 ERROR Upload failed error="upload failed" count=134212026/10/01 10:12:01 INFO Uploading batch count=134222026/10/01 10:12:01 ERROR Upload failed error="upload failed" count=134232026/10/01 10:12:01 INFO Uploading batch count=134242026/10/01 10:12:01 ERROR Upload failed error="upload failed" count=134252026/10/01 10:12:01 ERROR Drain finished with paths left in queue remaining=13426--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3427PASS