niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #334
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN 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 TestEncodeNixBase32WithRealHash97--- PASS: TestEncodeNixBase32WithRealHash (0.00s)98=== CONT TestShellSplit99=== CONT TestScriptTokenEmptyCommand100=== CONT TestScriptTokenScriptFails101=== CONT TestScriptTokenBadJSON102=== CONT TestScriptTokenEmptyToken103=== CONT TestScriptTokenCachesUntilRefresh104=== CONT TestScriptTokenNoExpiryRerunsEveryCall105=== CONT TestFileTokenEmpty106=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess107=== CONT TestFileTokenMissing108=== CONT TestFileTokenReadsAndCaches1092026/10/01 10:13:55 WARN Rate limiter enabled after throttle name=server-test rate=5110=== CONT TestStaticToken111=== CONT TestPathInfoHashCompatibility112=== CONT TestSetClientTLSErrors113=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)114=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestClientSignaturesByStorePath117=== CONT TestStreamPushReportsSignatures118=== CONT TestStreamPushRequestLine119=== CONT TestStreamPushGivesUpOnDeadServer120=== CONT TestStreamPushIsolatesFailures121=== CONT TestStreamPushBatchesUnderLoad122=== CONT TestStreamPushReportsEveryPath123=== CONT TestUploadMultipart_SupersededByPeer124=== CONT TestShellSplitErrors125--- PASS: TestShellSplit (0.00s)126=== CONT TestResolveStorePath127=== CONT TestDoWithRetry_BodyReplayedViaGetBody128=== CONT TestSetClientTLS129=== CONT TestParsePathInfoJSONMultiplePaths130=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon131=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon132=== CONT TestEncodeNixBase32133--- PASS: TestScriptTokenEmptyCommand (0.00s)134--- PASS: TestScriptTokenScriptFails (0.00s)135--- PASS: TestStaticToken (0.00s)136--- PASS: TestClientSignaturesByStorePath (0.00s)137--- PASS: TestFileTokenEmpty (0.00s)138--- PASS: TestFileTokenReadsAndCaches (0.00s)139--- PASS: TestShellSplitErrors (0.00s)140--- PASS: TestScriptTokenBadJSON (0.01s)141--- PASS: TestScriptTokenEmptyToken (0.01s)142=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI143=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI144=== RUN TestEncodeNixBase32/test_string_hash145=== PAUSE TestEncodeNixBase32/test_string_hash146=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1472026/10/01 10:13:55 ERROR Upload failed error="bad path" count=3148=== CONT TestDumpPathWriterError149=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== CONT TestGetStorePathHash151=== CONT TestDumpPathSingleFile152=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121532026/10/01 10:13:55 ERROR Upload failed error="connection refused" count=20154=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121552026/10/01 10:13:55 ERROR Server seems unavailable, giving up on batch untried=17156=== CONT TestParsePathInfoJSON157=== RUN TestGetStorePathHash/valid_store_path158=== RUN TestParsePathInfoJSON/Nix_format159=== PAUSE TestParsePathInfoJSON/Nix_format160=== CONT TestRateLimiterFeedback1612026/10/01 10:13:55 ERROR Upload failed error=boom count=11622026/10/01 10:13:55 ERROR Upload failed error=boom count=1163=== PAUSE TestGetStorePathHash/valid_store_path164=== RUN TestGetStorePathHash/basename_without_hyphen_should_error165=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error166=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths167=== RUN TestParsePathInfoJSON/Lix_format168=== PAUSE TestParsePathInfoJSON/Lix_format169=== RUN TestUploadMultipart_SupersededByPeer/exists170=== CONT TestConvertHashToNix32171=== RUN TestConvertHashToNix32/SRI_format_to_Nix32172=== RUN TestEncodeNixBase32/empty_input173--- PASS: TestFileTokenMissing (0.00s)174--- PASS: TestResolveStorePath (0.00s)175=== CONT TestDumpPathMatchesNix176=== CONT TestFilterOversizedClosures177=== CONT TestPartSizeForNAR178=== CONT TestUploadMultipart_PartsInParallel179=== RUN TestSetClientTLSErrors/missing_cert_file180=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error181=== CONT TestCaseHackSuffix182=== CONT TestRegisterUploadedObjectReusesConnections183=== RUN TestRateLimiterFeedback/429_enables_limiter184=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths185=== RUN TestParsePathInfoJSON/empty_input186=== PAUSE TestUploadMultipart_SupersededByPeer/exists187=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32188--- PASS: TestStreamPushReportsEveryPath (0.00s)189=== RUN TestConvertHashToNix32/already_Nix32_format1902026/10/01 10:13:55 WARN Rate limiter enabled after throttle name=server-test rate=51912026/10/01 10:13:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41653192--- PASS: TestStreamPushIsolatesFailures (0.00s)193--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)194--- PASS: TestStreamPushReportsSignatures (0.00s)195--- PASS: TestDoServerRequestAttachesToken (0.01s)196=== RUN TestUploadMultipart_SupersededByPeer/missing197=== PAUSE TestConvertHashToNix32/already_Nix32_format198=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512199=== PAUSE TestEncodeNixBase32/empty_input200=== CONT TestPathInfoCACompatibility201=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error202=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)203=== RUN TestPartSizeForNAR/zero_stays_at_minimum204=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI205=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths206=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error2072026/10/01 10:13:55 WARN Rate limiter backed off name=server-test rate=52082026/10/01 10:13:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41653209=== PAUSE TestParsePathInfoJSON/empty_input210=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error211=== CONT TestEncodeNixBase32/empty_input212=== PAUSE TestSetClientTLSErrors/missing_cert_file213=== RUN TestSetClientTLSErrors/missing_key_file214--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)215--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)216=== RUN TestSetClientTLS/rejects_connection_without_client_cert217=== RUN TestPathInfoCACompatibility/null_ca_field218=== RUN TestConvertHashToNix32/invalid_format219=== PAUSE TestUploadMultipart_SupersededByPeer/missing220=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum221=== RUN TestFilterOversizedClosures/no_limit_keeps_everything222=== CONT TestEncodeNixBase32/test_string_hash223=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon224=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths225=== CONT TestUploadMultipart_SupersededByPeer/missing226=== PAUSE TestRateLimiterFeedback/429_enables_limiter227=== RUN TestParsePathInfoJSON/whitespace_only228=== PAUSE TestParsePathInfoJSON/whitespace_only229=== CONT TestGetStorePathHash/valid_store_path230=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error231=== CONT TestGetStorePathHash/basename_without_hyphen_should_error232=== PAUSE TestSetClientTLSErrors/missing_key_file233--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)234=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert235=== PAUSE TestPathInfoCACompatibility/null_ca_field236=== PAUSE TestConvertHashToNix32/invalid_format237=== CONT TestConvertHashToNix32/SRI_format_to_Nix32238=== CONT TestConvertHashToNix32/invalid_format239=== RUN TestPartSizeForNAR/small_stays_at_minimum240=== PAUSE TestPartSizeForNAR/small_stays_at_minimum241=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything242=== CONT TestUploadMultipart_SupersededByPeer/exists243=== RUN TestRateLimiterFeedback/503_enables_limiter244=== RUN TestParsePathInfoJSON/invalid_JSON245=== RUN TestSetClientTLSErrors/missing_ca_file246=== PAUSE TestSetClientTLSErrors/missing_ca_file247--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)248=== RUN TestSetClientTLSErrors/invalid_ca_file249=== PAUSE TestSetClientTLSErrors/invalid_ca_file250=== CONT TestSetClientTLSErrors/missing_cert_file251=== CONT TestSetClientTLSErrors/invalid_ca_file252=== CONT TestSetClientTLSErrors/missing_ca_file253--- PASS: TestEncodeNixBase32 (0.01s)254 --- PASS: TestEncodeNixBase32/empty_input (0.00s)255 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)256--- PASS: TestDumpPathSingleFile (0.04s)257=== CONT TestSetClientTLSErrors/missing_key_file258--- PASS: TestPathInfoHashCompatibility (0.00s)259 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)260 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)261 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)262 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)263--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)264 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)265 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)266--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)267 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)268 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)269=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error270=== CONT TestConvertHashToNix32/already_Nix32_format271=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum272=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum273=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped274--- PASS: TestConvertHashToNix32 (0.04s)275 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)276 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)277 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)278--- PASS: TestGetStorePathHash (0.04s)279 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)280 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)281 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)282 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)283=== PAUSE TestRateLimiterFeedback/503_enables_limiter284=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter285=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter286=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter287=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter288=== PAUSE TestParsePathInfoJSON/invalid_JSON289=== CONT TestParsePathInfoJSON/Nix_format290=== CONT TestParsePathInfoJSON/whitespace_only291=== RUN TestPathInfoCACompatibility/old_string_format_-_text292=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts293=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts294=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped295--- PASS: TestSetClientTLSErrors (0.05s)296 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)297 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)298 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)299 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)300=== RUN TestFilterOversizedClosures/all_closures_skipped301=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter302=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter303=== CONT TestRateLimiterFeedback/503_enables_limiter304=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA305=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA306=== RUN TestSetClientTLS/preserves_debug_logging_transport307=== PAUSE TestSetClientTLS/preserves_debug_logging_transport308=== CONT TestParsePathInfoJSON/empty_input309=== CONT TestParsePathInfoJSON/Lix_format310=== CONT TestParsePathInfoJSON/invalid_JSON311--- PASS: TestParsePathInfoJSON (0.04s)312 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)313 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)314 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)315 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)316 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)317=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text318=== RUN TestPartSizeForNAR/1_TiB319=== PAUSE TestPartSizeForNAR/1_TiB320=== CONT TestRateLimiterFeedback/429_enables_limiter321=== PAUSE TestFilterOversizedClosures/all_closures_skipped322=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3232026/10/01 10:13:55 WARN Rate limiter enabled after throttle name=server-test rate=5324=== CONT TestFilterOversizedClosures/all_closures_skipped3252026/10/01 10:13:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:454653262026/10/01 10:13:55 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=50327=== RUN TestPartSizeForNAR/5_TiB_S3_max_object3282026/10/01 10:13:55 WARN Rate limiter backed off name=server-test rate=5329=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3302026/10/01 10:13:55 WARN Rate limiter enabled after throttle name=server-test rate=5331=== CONT TestSetClientTLS/preserves_debug_logging_transport3322026/10/01 10:13:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33169333=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3342026/10/01 10:13:55 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=2000335=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive3362026/10/01 10:13:55 WARN Rate limiter backed off name=server-test rate=5337=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive338=== CONT TestSetClientTLS/rejects_connection_without_client_cert339=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object340--- PASS: TestFilterOversizedClosures (0.04s)341 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)342 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)343 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)344=== RUN TestPathInfoCACompatibility/new_structured_format_-_text345=== RUN TestPartSizeForNAR/capped_at_5_GiB346=== PAUSE TestPartSizeForNAR/capped_at_5_GiB347=== CONT TestPartSizeForNAR/zero_stays_at_minimum348=== CONT TestPartSizeForNAR/5_TiB_S3_max_object349=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text350=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method351=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method352=== CONT TestPathInfoCACompatibility/null_ca_field353=== CONT TestPartSizeForNAR/1_TiB354=== CONT TestPathInfoCACompatibility/new_structured_format_-_text355--- PASS: TestRateLimiterFeedback (0.04s)356 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)357 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)360=== CONT TestPartSizeForNAR/capped_at_5_GiB361=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum362=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts363=== CONT TestPartSizeForNAR/small_stays_at_minimum364=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method365=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive366=== CONT TestPathInfoCACompatibility/old_string_format_-_text367--- PASS: TestPartSizeForNAR (0.04s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)372 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)374 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)375--- PASS: TestPathInfoCACompatibility (0.04s)376 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)377 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.01s)381--- PASS: TestStreamPushRequestLine (0.07s)3822026/10/01 10:13:55 http: TLS handshake error from 127.0.0.1:50942: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.05s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)388--- PASS: TestCaseHackSuffix (0.07s)389--- PASS: TestDumpPathWriterError (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres2806992054/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/postgres2806992054/data -l logfile start422423/build/postgres2806992054:5432 - no response4242026-10-01 10:13:56.886 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:13:56.887 UTC [128] LOG: listening on Unix socket "/build/postgres2806992054/.s.PGSQL.5432"4262026-10-01 10:13:56.892 UTC [135] LOG: database system was shut down at 2026-10-01 10:13:56 UTC4272026-10-01 10:13:56.896 UTC [128] LOG: database system is ready to accept connections428/build/postgres2806992054:5432 - accepting connections429{"timestamp":"2026-10-01T10:13:57.191267885Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6e6c5d11-712b-4c37-a9df-aae9a4e23d64","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(388)"}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:13:57.391 UTC [568] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 10:13:57.391 UTC [568] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 10:13:57 OK 20241026095416_initial_model.sql (7.48ms)4762026/10/01 10:13:57 OK 20251210153512_drop_unused_gin_index.sql (5.72ms)4772026/10/01 10:13:57 OK 20251218171726_add_pins.sql (2.04ms)4782026/10/01 10:13:57 OK 20260628120000_add_object_size_and_stats.sql (1.81ms)4792026/10/01 10:13:57 OK 20260905000000_add_claims.sql (2.39ms)4802026/10/01 10:13:57 OK 20260920000000_drop_claims.sql (1.46ms)4812026/10/01 10:13:57 OK 20260923120000_add_pushes.sql (1.03ms)4822026/10/01 10:13:57 goose: successfully migrated database to version: 202609231200004832026/10/01 10:13:57 OK 1_commit_pending_closure.sql (1.33ms)4842026/10/01 10:13:57 OK 2_object_stats_trigger.sql (584.35µs)4852026/10/01 10:13:57 OK 3_commit_push.sql (475.1µs)4862026/10/01 10:13:57 goose: up to current file version: 34872026/10/01 10:13:57 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 10:13:58 INFO lead: released remote=192.0.2.1:12344892026/10/01 10:13:58 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 10:13:58 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.81s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 10:13:58.175 UTC [578] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 10:13:58.175 UTC [578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 10:13:58 OK 20241026095416_initial_model.sql (7.13ms)4982026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (946.44µs)4992026/10/01 10:13:58 OK 20251218171726_add_pins.sql (2.2ms)5002026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (2.37ms)5012026/10/01 10:13:58 OK 20260905000000_add_claims.sql (1.95ms)5022026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (1.33ms)5032026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (929.5µs)5042026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200005052026/10/01 10:13:58 OK 1_commit_pending_closure.sql (1.43ms)5062026/10/01 10:13:58 OK 2_object_stats_trigger.sql (731.09µs)5072026/10/01 10:13:58 OK 3_commit_push.sql (679.03µs)5082026/10/01 10:13:58 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)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:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:13:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 10:13:58 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 TestPresentReportsOnlyClosureRoots692=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit693=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT694=== CONT TestCompleteMultipartUnregistered695=== CONT TestService_verifyS3Integrity696=== CONT TestService_createPendingClosureHandler697=== CONT TestService_cleanupPendingClosuresHandler698=== CONT TestUploadHandlersRejectOversizedBody699=== CONT TestUploadHandlersRejectInvalidKeys700=== CONT TestIsValidUploadKey701=== RUN TestIsValidUploadKey/narinfo702=== CONT TestProxyWriteTimeout703=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle704=== CONT TestSkippedUploadsHandler705=== CONT TestParseSize706=== CONT TestService_Rustfstest707=== CONT TestPresignedUploadRegisteredBeforeCommit708=== CONT TestCompletedNarNotReofferedAcrossClosures709=== CONT TestCompleteMultipartUpload_ErrorButObjectExists710=== CONT TestRedundantMultipartUpload711=== CONT TestPush_SignsNarinfosOfItsPendingObjects712=== CONT TestPush_RejectsBadRequests713=== CONT TestSweepSkipsRowsLockedByPush714=== CONT TestCreatePin_ReservedPins715=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info716=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info717=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal718=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal719=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key720=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key721=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key722=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key723=== PAUSE TestIsValidUploadKey/narinfo724=== RUN TestIsValidUploadKey/nar_zst725=== PAUSE TestIsValidUploadKey/nar_zst726=== RUN TestIsValidUploadKey/nar_xz727=== PAUSE TestIsValidUploadKey/nar_xz728=== RUN TestIsValidUploadKey/nar_plain729--- PASS: TestParseSize (0.00s)730=== CONT TestOrphanedObjectsGCStressTest731=== RUN TestProxyWriteTimeout/narinfo732=== PAUSE TestIsValidUploadKey/nar_plain733=== RUN TestIsValidUploadKey/listing734=== PAUSE TestProxyWriteTimeout/narinfo7352026/10/01 10:13:58 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000736=== RUN TestProxyWriteTimeout/1_GiB_nar737=== CONT TestOrphanedObjectsGC738=== PAUSE TestIsValidUploadKey/listing739=== PAUSE TestProxyWriteTimeout/1_GiB_nar740=== RUN TestProxyWriteTimeout/10_GiB_nar741=== RUN TestIsValidUploadKey/build_log742=== PAUSE TestProxyWriteTimeout/10_GiB_nar743=== RUN TestProxyWriteTimeout/unknown_size744=== PAUSE TestProxyWriteTimeout/unknown_size745=== PAUSE TestIsValidUploadKey/build_log746=== RUN TestIsValidUploadKey/build_log_home-manager_file747=== PAUSE TestIsValidUploadKey/build_log_home-manager_file748=== RUN TestIsValidUploadKey/build_log_plus_in_name749=== PAUSE TestIsValidUploadKey/build_log_plus_in_name750=== CONT TestObjectStatsTrigger751=== RUN TestIsValidUploadKey/build_log_question_mark752=== PAUSE TestIsValidUploadKey/build_log_question_mark753=== RUN TestIsValidUploadKey/build_log_equals754=== PAUSE TestIsValidUploadKey/build_log_equals755=== RUN TestIsValidUploadKey/realisation756=== PAUSE TestIsValidUploadKey/realisation757=== RUN TestIsValidUploadKey/realisation_plus_in_output758=== PAUSE TestIsValidUploadKey/realisation_plus_in_output759=== RUN TestIsValidUploadKey/nix-cache-info760=== PAUSE TestIsValidUploadKey/nix-cache-info761=== RUN TestIsValidUploadKey/index.html762=== PAUSE TestIsValidUploadKey/index.html763=== RUN TestIsValidUploadKey/narinfo_key,_nar_type764=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type765=== RUN TestIsValidUploadKey/nar_key,_narinfo_type766=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type767=== RUN TestIsValidUploadKey/listing_key,_narinfo_type768=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type769=== RUN TestIsValidUploadKey/traversal770=== PAUSE TestIsValidUploadKey/traversal771=== RUN TestIsValidUploadKey/traversal_nar772=== PAUSE TestIsValidUploadKey/traversal_nar773=== RUN TestIsValidUploadKey/absolute774=== PAUSE TestIsValidUploadKey/absolute775=== RUN TestIsValidUploadKey/empty_key776=== PAUSE TestIsValidUploadKey/empty_key777=== RUN TestIsValidUploadKey/unknown_type778=== PAUSE TestIsValidUploadKey/unknown_type779=== CONT TestPendingCleanupUsesOneCutoff780--- PASS: TestSkippedUploadsHandler (0.13s)781=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded7822026/10/01 10:13:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46091/oidc783=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts784=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts785=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure786=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure787=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart788=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart789=== CONT TestMultipartCleanup7902026-10-01 10:13:58.757 UTC [645] ERROR: relation "goose_db_version" does not exist at character 367912026-10-01 10:13:58.757 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026-10-01 10:13:58.766 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367932026-10-01 10:13:58.766 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026-10-01 10:13:58.796 UTC [647] ERROR: relation "goose_db_version" does not exist at character 367952026-10-01 10:13:58.796 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026/10/01 10:13:58 OK 20241026095416_initial_model.sql (29.85ms)7972026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)7982026/10/01 10:13:58 OK 20241026095416_initial_model.sql (32.78ms)7992026/10/01 10:13:58 OK 20251218171726_add_pins.sql (8.16ms)8002026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (4.83ms)8012026/10/01 10:13:58 OK 20241026095416_initial_model.sql (29.73ms)8022026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)8032026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)8042026/10/01 10:13:58 OK 20251218171726_add_pins.sql (6.65ms)8052026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.77ms)8062026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.18ms)8072026-10-01 10:13:58.853 UTC [648] ERROR: relation "goose_db_version" does not exist at character 368082026-10-01 10:13:58.853 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.04ms)8102026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (6.88ms)8112026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.81ms)8122026-10-01 10:13:58.856 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368132026-10-01 10:13:58.856 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-10-01 10:13:58.856 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368152026-10-01 10:13:58.856 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026-10-01 10:13:58.857 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368172026-10-01 10:13:58.857 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026-10-01 10:13:58.866 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368192026-10-01 10:13:58.866 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026-10-01 10:13:58.866 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368212026-10-01 10:13:58.866 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-10-01 10:13:58.868 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368232026-10-01 10:13:58.868 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (14.3ms)8252026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200008262026/10/01 10:13:58 OK 20260905000000_add_claims.sql (16.61ms)8272026/10/01 10:13:58 OK 20260905000000_add_claims.sql (17.99ms)8282026/10/01 10:13:58 OK 1_commit_pending_closure.sql (6.39ms)8292026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (4.4ms)8302026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.22ms)8312026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (7.57ms)8322026/10/01 10:13:58 OK 3_commit_push.sql (2.79ms)8332026/10/01 10:13:58 goose: up to current file version: 38342026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (4.47ms)8352026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200008362026-10-01 10:13:58.885 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368372026-10-01 10:13:58.885 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026/10/01 10:13:58 OK 1_commit_pending_closure.sql (4.67ms)8392026-10-01 10:13:58.889 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368402026-10-01 10:13:58.889 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8412026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (8.27ms)8422026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200008432026/10/01 10:13:58 OK 2_object_stats_trigger.sql (3.56ms)8442026-10-01 10:13:58.891 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368452026-10-01 10:13:58.891 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8462026/10/01 10:13:58 OK 3_commit_push.sql (2.47ms)8472026/10/01 10:13:58 goose: up to current file version: 38482026/10/01 10:13:58 OK 1_commit_pending_closure.sql (5.69ms)8492026/10/01 10:13:58 OK 2_object_stats_trigger.sql (5.14ms)8502026/10/01 10:13:58 OK 20241026095416_initial_model.sql (25.07ms)8512026/10/01 10:13:58 OK 20241026095416_initial_model.sql (20.33ms)8522026/10/01 10:13:58 OK 3_commit_push.sql (3.21ms)8532026/10/01 10:13:58 goose: up to current file version: 38542026/10/01 10:13:58 OK 20241026095416_initial_model.sql (23.4ms)8552026/10/01 10:13:58 OK 20241026095416_initial_model.sql (22.18ms)8562026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (4.22ms)8572026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)8582026/10/01 10:13:58 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"859--- PASS: TestService_AuthMiddleware (0.45s)860=== CONT TestServerTLSConfig861=== RUN TestServerTLSConfig/no_client_CA862=== PAUSE TestServerTLSConfig/no_client_CA863=== RUN TestServerTLSConfig/missing_CA_file864=== PAUSE TestServerTLSConfig/missing_CA_file865=== RUN TestServerTLSConfig/not_a_PEM_file866=== PAUSE TestServerTLSConfig/not_a_PEM_file867=== CONT TestService_NativeMTLS8682026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)8692026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (12.93ms)8702026/10/01 10:13:58 OK 20251218171726_add_pins.sql (19.17ms)8712026/10/01 10:13:58 OK 20251218171726_add_pins.sql (19.28ms)8722026/10/01 10:13:58 OK 20251218171726_add_pins.sql (17.22ms)8732026/10/01 10:13:58 OK 20241026095416_initial_model.sql (33.48ms)8742026/10/01 10:13:58 OK 20241026095416_initial_model.sql (33.51ms)8752026/10/01 10:13:58 OK 20241026095416_initial_model.sql (25.52ms)8762026/10/01 10:13:58 OK 20241026095416_initial_model.sql (34.08ms)8772026/10/01 10:13:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8782026/10/01 10:13:58 OK 20251218171726_add_pins.sql (13.04ms)8792026/10/01 10:13:58 OK 20241026095416_initial_model.sql (25.17ms)8802026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (5.25ms)8812026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (3.99ms)8822026/10/01 10:13:58 OK 20241026095416_initial_model.sql (26.65ms)8832026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (6.62ms)8842026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)8852026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (6.78ms)8862026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (9.52ms)8872026/10/01 10:13:58 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst8882026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)889--- PASS: TestCompleteMultipartUnregistered (0.48s)8902026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.57ms)891=== CONT TestMetricsInventory8922026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (10.81ms)8932026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (10.4ms)8942026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.45ms)8952026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)8962026-10-01 10:13:58.937 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368972026-10-01 10:13:58.937 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.1ms)8992026/10/01 10:13:58 OK 20251218171726_add_pins.sql (5.18ms)9002026-10-01 10:13:58.939 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369012026-10-01 10:13:58.939 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9022026/10/01 10:13:58 OK 20251218171726_add_pins.sql (5.85ms)9032026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)9042026/10/01 10:13:58 OK 20251218171726_add_pins.sql (5.51ms)9052026/10/01 10:13:58 OK 20260905000000_add_claims.sql (5.29ms)9062026/10/01 10:13:58 OK 20260905000000_add_claims.sql (5.05ms)9072026/10/01 10:13:58 OK 20260905000000_add_claims.sql (6.53ms)9082026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.39ms)9092026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.85ms)9102026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)9112026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (6.25ms)9122026-10-01 10:13:58.944 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369132026-10-01 10:13:58.944 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9142026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.16ms)9152026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.41ms)9162026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.35ms)9172026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.26ms)9182026-10-01 10:13:58.945 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369192026-10-01 10:13:58.945 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026/10/01 10:13:58 OK 20260905000000_add_claims.sql (3.28ms)9212026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (4.05ms)9222026/10/01 10:13:58 OK 20260905000000_add_claims.sql (3.47ms)9232026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)9242026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (6.9ms)9252026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.51ms)9262026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009272026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.78ms)9282026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009292026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.97ms)9302026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009312026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (3.02ms)9322026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009332026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.62ms)9342026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.08ms)9352026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.98ms)9362026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.85ms)9372026/10/01 10:13:58 OK 20260905000000_add_claims.sql (3.98ms)9382026/10/01 10:13:58 OK 1_commit_pending_closure.sql (4.21ms)9392026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.42ms)9402026/10/01 10:13:58 OK 1_commit_pending_closure.sql (4.67ms)9412026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (3.37ms)9422026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009432026/10/01 10:13:58 OK 1_commit_pending_closure.sql (4ms)9442026/10/01 10:13:58 OK 20260905000000_add_claims.sql (6.46ms)9452026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (3.16ms)9462026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009472026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (3.3ms)9482026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009492026/10/01 10:13:58 OK 1_commit_pending_closure.sql (4.6ms)9502026/10/01 10:13:58 OK 2_object_stats_trigger.sql (1.38ms)9512026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.11ms)9522026-10-01 10:13:58.954 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369532026-10-01 10:13:58.954 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9542026-10-01 10:13:58.954 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369552026-10-01 10:13:58.954 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9562026/10/01 10:13:58 INFO Received uploads request method=POST path=/api/pending_closures9572026/10/01 10:13:58 OK 3_commit_push.sql (1.55ms)9582026/10/01 10:13:58 goose: up to current file version: 39592026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.7ms)9602026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009612026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.36ms)9622026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.07ms)9632026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.13ms)9642026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009652026/10/01 10:13:58 OK 1_commit_pending_closure.sql (2.57ms)9662026/10/01 10:13:58 OK 1_commit_pending_closure.sql (2.8ms)9672026/10/01 10:13:58 OK 2_object_stats_trigger.sql (1.8ms)9682026/10/01 10:13:58 OK 1_commit_pending_closure.sql (3.07ms)9692026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.69ms)9702026/10/01 10:13:58 OK 3_commit_push.sql (1.9ms)9712026/10/01 10:13:58 goose: up to current file version: 39722026/10/01 10:13:58 OK 3_commit_push.sql (1.82ms)9732026/10/01 10:13:58 goose: up to current file version: 39742026/10/01 10:13:58 OK 2_object_stats_trigger.sql (1.65ms)9752026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.18ms)9762026/10/01 10:13:58 OK 3_commit_push.sql (2.14ms)9772026/10/01 10:13:58 goose: up to current file version: 39782026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.32ms)9792026/10/01 10:13:58 OK 1_commit_pending_closure.sql (2.67ms)9802026/10/01 10:13:58 OK 1_commit_pending_closure.sql (3.45ms)9812026-10-01 10:13:58.959 UTC [672] ERROR: relation "goose_db_version" does not exist at character 369822026-10-01 10:13:58.959 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9832026/10/01 10:13:58 OK 3_commit_push.sql (2.09ms)9842026/10/01 10:13:58 goose: up to current file version: 39852026/10/01 10:13:58 OK 20241026095416_initial_model.sql (11.21ms)9862026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (3.42ms)9872026/10/01 10:13:58 goose: successfully migrated database to version: 202609231200009882026/10/01 10:13:58 OK 2_object_stats_trigger.sql (1.81ms)9892026/10/01 10:13:58 OK 3_commit_push.sql (2.05ms)9902026/10/01 10:13:58 goose: up to current file version: 39912026/10/01 10:13:58 OK 3_commit_push.sql (1.88ms)9922026/10/01 10:13:58 goose: up to current file version: 39932026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.13ms)9942026/10/01 10:13:58 OK 3_commit_push.sql (1.55ms)9952026/10/01 10:13:58 goose: up to current file version: 39962026/10/01 10:13:58 OK 20241026095416_initial_model.sql (10.52ms)9972026-10-01 10:13:58.963 UTC [673] ERROR: relation "goose_db_version" does not exist at character 369982026-10-01 10:13:58.963 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9992026/10/01 10:13:58 OK 3_commit_push.sql (1.86ms)10002026/10/01 10:13:58 goose: up to current file version: 310012026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)10022026-10-01 10:13:58.964 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3610032026-10-01 10:13:58.964 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10042026/10/01 10:13:58 OK 1_commit_pending_closure.sql (3.59ms)10052026/10/01 10:13:58 OK 20241026095416_initial_model.sql (11.24ms)10062026/10/01 10:13:58 OK 20241026095416_initial_model.sql (12.3ms)10072026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)10082026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)10092026-10-01 10:13:58.967 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3610102026-10-01 10:13:58.967 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10112026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.6ms)10122026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.17ms)10132026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)10142026/10/01 10:13:58 OK 3_commit_push.sql (1.53ms)10152026/10/01 10:13:58 goose: up to current file version: 310162026/10/01 10:13:58 OK 20251218171726_add_pins.sql (3.23ms)10172026-10-01 10:13:58.969 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3610182026-10-01 10:13:58.969 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10192026/10/01 10:13:58 OK 20251218171726_add_pins.sql (3.14ms)10202026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.51ms)10212026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)10222026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)10232026/10/01 10:13:58 OK 20241026095416_initial_model.sql (10.7ms)1024--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.52s)1025=== CONT TestNARDeduplicationMetadataUploadBug10262026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)10272026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)10282026/10/01 10:13:58 OK 20241026095416_initial_model.sql (11.12ms)10292026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.01ms)10302026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.19ms)10312026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)10322026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.4ms)10332026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)10342026/10/01 10:13:58 OK 20251218171726_add_pins.sql (3.88ms)10352026/10/01 10:13:58 OK 20241026095416_initial_model.sql (11.91ms)10362026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (2.35ms)10372026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.19ms)10382026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.34ms)10392026/10/01 10:13:58 OK 20260905000000_add_claims.sql (3.95ms)10402026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.5ms)10412026/10/01 10:13:58 goose: successfully migrated database to version: 2026092312000010422026/10/01 10:13:58 OK 20251218171726_add_pins.sql (5.34ms)10432026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (3.63ms)10442026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.88ms)10452026/10/01 10:13:58 goose: successfully migrated database to version: 2026092312000010462026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (3.01ms)10472026/10/01 10:13:58 goose: successfully migrated database to version: 2026092312000010482026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)10492026/10/01 10:13:58 OK 20241026095416_initial_model.sql (12.12ms)10502026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (2.96ms)10512026/10/01 10:13:58 OK 20241026095416_initial_model.sql (11.58ms)10522026/10/01 10:13:58 OK 1_commit_pending_closure.sql (2.54ms)10532026/10/01 10:13:58 OK 1_commit_pending_closure.sql (3.21ms)10542026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)10552026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)10562026/10/01 10:13:58 OK 1_commit_pending_closure.sql (3.46ms)10572026/10/01 10:13:58 OK 20260905000000_add_claims.sql (3.43ms)10582026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.51ms)10592026/10/01 10:13:58 goose: successfully migrated database to version: 2026092312000010602026/10/01 10:13:58 OK 20241026095416_initial_model.sql (13.77ms)10612026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.01ms)10622026/10/01 10:13:58 OK 2_object_stats_trigger.sql (1.51ms)10632026/10/01 10:13:58 OK 20241026095416_initial_model.sql (10.91ms)10642026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)10652026/10/01 10:13:58 OK 2_object_stats_trigger.sql (1.68ms)10662026/10/01 10:13:58 OK 2_object_stats_trigger.sql (2.16ms)10672026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)10682026/10/01 10:13:58 OK 3_commit_push.sql (1.55ms)10692026/10/01 10:13:58 goose: up to current file version: 310702026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (2.64ms)10712026/10/01 10:13:58 OK 3_commit_push.sql (1.74ms)10722026/10/01 10:13:58 goose: up to current file version: 310732026/10/01 10:13:58 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)10742026/10/01 10:13:58 OK 1_commit_pending_closure.sql (3.68ms)10752026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.3ms)10762026/10/01 10:13:58 OK 20251218171726_add_pins.sql (4.44ms)10772026/10/01 10:13:58 OK 3_commit_push.sql (1.86ms)10782026/10/01 10:13:58 goose: up to current file version: 310792026/10/01 10:13:58 OK 20260905000000_add_claims.sql (4.33ms)10802026/10/01 10:13:58 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)10812026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.62ms)10822026/10/01 10:13:58 goose: successfully migrated database to version: 2026092312000010832026/10/01 10:13:58 OK 20260920000000_drop_claims.sql (3.28ms)10842026/10/01 10:13:58 OK 2_object_stats_trigger.sql (4.79ms)10852026/10/01 10:13:58 OK 20251218171726_add_pins.sql (6.54ms)10862026/10/01 10:13:58 OK 1_commit_pending_closure.sql (4.4ms)10872026/10/01 10:13:58 OK 20251218171726_add_pins.sql (7.6ms)10882026/10/01 10:13:58 OK 3_commit_push.sql (2.03ms)10892026/10/01 10:13:58 goose: up to current file version: 310902026/10/01 10:13:58 OK 20260905000000_add_claims.sql (5.83ms)10912026/10/01 10:13:58 OK 20260923120000_add_pushes.sql (2.67ms)10922026/10/01 10:13:58 goose: successfully migrated database to version: 2026092312000010932026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (7.57ms)10942026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (7.71ms)10952026/10/01 10:13:59 OK 2_object_stats_trigger.sql (2.74ms)10962026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (10.23ms)10972026/10/01 10:13:59 OK 20260905000000_add_claims.sql (11.45ms)10982026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (13.46ms)10992026/10/01 10:13:59 OK 3_commit_push.sql (10.65ms)11002026/10/01 10:13:59 goose: up to current file version: 311012026/10/01 10:13:59 OK 1_commit_pending_closure.sql (12.09ms)11022026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (13.55ms)11032026/10/01 10:13:59 OK 20260905000000_add_claims.sql (11.54ms)1104--- PASS: TestPresentReportsOnlyClosureRoots (0.56s)1105=== CONT TestCreatePendingClosureRejectsOversizedNAR11062026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.8ms)11072026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011082026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures1109--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1110=== CONT TestCacheConfigHandlerMaxNarSize1111--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1112=== CONT TestGenerateLandingPage11132026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.68ms)11142026/10/01 10:13:59 OK 2_object_stats_trigger.sql (3.09ms)11152026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (3.5ms)11162026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3.61ms)11172026/10/01 10:13:59 OK 20260905000000_add_claims.sql (4.76ms)11182026/10/01 10:13:59 OK 20260905000000_add_claims.sql (4.47ms)11192026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (3.18ms)11202026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011212026/10/01 10:13:59 OK 3_commit_push.sql (2.45ms)11222026/10/01 10:13:59 goose: up to current file version: 31123--- PASS: TestGenerateLandingPage (0.00s)1124=== CONT TestService_readinessHandler11252026/10/01 10:13:59 OK 2_object_stats_trigger.sql (2.27ms)11262026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (3.07ms)11272026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011282026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.82ms)11292026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.92ms)11302026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures11332026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.39ms)11342026/10/01 10:13:59 OK 3_commit_push.sql (2.21ms)11352026/10/01 10:13:59 goose: up to current file version: 311362026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.82ms)11372026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.25ms)11382026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011392026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.2ms)11402026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011412026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.39ms)11422026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.65ms)11432026/10/01 10:13:59 OK 3_commit_push.sql (2.15ms)11442026/10/01 10:13:59 goose: up to current file version: 311452026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.49ms)11462026/10/01 10:13:59 OK 3_commit_push.sql (1.88ms)11472026/10/01 10:13:59 goose: up to current file version: 311482026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3.29ms)11492026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.39ms)11502026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.55ms)11512026/10/01 10:13:59 OK 3_commit_push.sql (1.91ms)11522026/10/01 10:13:59 goose: up to current file version: 311532026/10/01 10:13:59 OK 3_commit_push.sql (1.93ms)11542026/10/01 10:13:59 goose: up to current file version: 311552026-10-01 10:13:59.039 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3611562026-10-01 10:13:59.039 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures11582026-10-01 10:13:59.051 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3611592026-10-01 10:13:59.051 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11602026/10/01 10:13:59 OK 20241026095416_initial_model.sql (9.31ms)11612026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)11622026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.44ms)11632026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)11642026/10/01 10:13:59 OK 20241026095416_initial_model.sql (9.29ms)11652026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)11662026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.27ms)11672026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.06ms)11682026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.07ms)11692026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.69ms)11702026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011712026/10/01 10:13:59 INFO Received cleanup request method=DELETE path=/api/pending_closures11722026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.5ms)11732026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)11742026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.34ms)11752026/10/01 10:13:59 OK 3_commit_push.sql (1.06ms)11762026/10/01 10:13:59 goose: up to current file version: 311772026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.11ms)11782026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=011792026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.35ms)11802026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.17ms)11822026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000011832026-10-01 10:13:59.084 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611842026-10-01 10:13:59.084 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.7ms)11862026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.87ms)11872026/10/01 10:13:59 OK 3_commit_push.sql (1.18ms)11882026/10/01 10:13:59 goose: up to current file version: 311892026/10/01 10:13:59 INFO Received cleanup request method=DELETE path=/api/pending_closures11902026/10/01 10:13:59 INFO Aborted multipart uploads count=1 kept=011912026/10/01 10:13:59 OK 20241026095416_initial_model.sql (8.24ms)11922026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)11932026/10/01 10:13:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11942026-10-01 10:13:59.101 UTC [651] ERROR: Closure does not exist: id=111952026-10-01 10:13:59.101 UTC [651] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11962026-10-01 10:13:59.101 UTC [651] STATEMENT: -- name: CommitPendingClosure :exec1197 SELECT commit_pending_closure($1::bigint)1198 1199--- PASS: TestService_cleanupPendingClosuresHandler (0.64s)1200=== CONT TestService_healthCheckHandler12012026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.76ms)12022026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures12032026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)12042026/10/01 10:13:59 OK 20260905000000_add_claims.sql (2.35ms)12052026-10-01 10:13:59.110 UTC [685] ERROR: relation "goose_db_version" does not exist at character 3612062026-10-01 10:13:59.110 UTC [685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12072026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (1.86ms)12082026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.17ms)12092026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000012102026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.59ms)12112026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.25ms)12122026/10/01 10:13:59 OK 3_commit_push.sql (1.32ms)12132026/10/01 10:13:59 goose: up to current file version: 312142026/10/01 10:13:59 OK 20241026095416_initial_model.sql (7.61ms)12152026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (904.36µs)12162026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.68ms)12172026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)12182026/10/01 10:13:59 OK 20260905000000_add_claims.sql (2.56ms)12192026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.09ms)12202026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.93ms)12212026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000012222026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.29ms)12232026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.5ms)12242026/10/01 10:13:59 OK 3_commit_push.sql (893.38µs)12252026/10/01 10:13:59 goose: up to current file version: 312262026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=01227--- PASS: TestService_Rustfstest (0.70s)1228=== CONT TestGracefulShutdownDrainsInflight12292026/10/01 10:13:59 INFO Starting HTTP server address=127.0.0.1:4222512302026/10/01 10:13:59 WARN Force mode enabled - objects will be deleted immediately without grace period12312026/10/01 10:13:59 INFO Shutdown signal received, draining in-flight requests timeout=10s12322026/10/01 10:13:59 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=012332026/10/01 10:13:59 INFO Vacuumed table table=pending_closures12342026/10/01 10:13:59 INFO Vacuumed table table=pending_objects12352026/10/01 10:13:59 INFO Vacuumed table table=multipart_uploads12362026/10/01 10:13:59 INFO Vacuumed table table=closures12372026/10/01 10:13:59 INFO Vacuumed table table=objects12382026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=012392026/10/01 10:13:59 WARN Force mode enabled - objects will be deleted immediately without grace period12402026-10-01 10:13:59.183 UTC [689] ERROR: relation "goose_db_version" does not exist at character 3612412026-10-01 10:13:59.183 UTC [689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12422026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/01 10:13:59 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=012442026/10/01 10:13:59 INFO Vacuumed table table=pending_closures12452026/10/01 10:13:59 INFO Vacuumed table table=pending_objects12462026/10/01 10:13:59 INFO Vacuumed table table=multipart_uploads12472026/10/01 10:13:59 INFO Vacuumed table table=closures12482026/10/01 10:13:59 OK 20241026095416_initial_model.sql (7.17ms)12492026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)12502026/10/01 10:13:59 INFO Vacuumed table table=objects1251--- PASS: TestSweepSkipsRowsLockedByPush (0.74s)1252=== CONT TestGCTaskStore_Fail1253--- PASS: TestGCTaskStore_Fail (0.00s)1254=== CONT TestGCTaskStore_PhaseUpdates12552026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.14ms)1256--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1257=== CONT TestGCTaskStore_CompletedAllowsNewTask1258--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1259=== CONT TestGCTaskStore_GetReturnsLatest1260--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1261=== CONT TestGCTaskStore_GetEmpty1262--- PASS: TestGCTaskStore_GetEmpty (0.00s)1263=== CONT TestGCTaskStore_ConflictDifferentParams1264--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1265=== CONT TestGCTaskStore_DeduplicateSameParams1266--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1267=== CONT TestGCTaskStore_StartNew1268--- PASS: TestGCTaskStore_StartNew (0.00s)1269=== CONT TestGCEndsOnShutdown12702026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (1.97ms)12712026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.2ms)12722026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (1.58ms)12732026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.07ms)12742026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000012752026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.35ms)12762026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.14ms)12772026/10/01 10:13:59 OK 3_commit_push.sql (705.02µs)12782026/10/01 10:13:59 goose: up to current file version: 312792026/10/01 10:13:59 INFO Received push request method=POST path=/api/pushes12802026/10/01 10:13:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12812026/10/01 10:13:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12822026/10/01 10:13:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LjcxZjZhZTcxLWY0N2QtNDUzMS04YmEwLWM3ODhiZjg4MWZkMngxNzkwODQ5NjM5MTkzNDM1ODAy1283--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1284=== CONT TestCommitRacingPendingCleanupKeepsObjects12852026/10/01 10:13:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12862026/10/01 10:13:59 INFO Signed narinfos id=1 count=11287--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.77s)1288=== CONT TestPushWaitsForSweepHoldingRow12892026/10/01 10:13:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LjcxZjZhZTcxLWY0N2QtNDUzMS04YmEwLWM3ODhiZjg4MWZkMngxNzkwODQ5NjM5MTkzNDM1ODAy parts=11290--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.78s)1291=== CONT TestSweepRechecksPendingAfterLocking12922026/10/01 10:13:59 INFO Received push request method=POST path=/api/pushes12932026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures12942026/10/01 10:13:59 INFO Received complete push request method=POST path=/api/pushes/1/complete12952026-10-01 10:13:59.298 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3612962026-10-01 10:13:59.298 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/10/01 10:13:59 INFO Received push request method=POST path=/api/pushes12982026/10/01 10:13:59 OK 20241026095416_initial_model.sql (18.43ms)12992026/10/01 10:13:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13002026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures13012026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)13022026/10/01 10:13:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13032026/10/01 10:13:59 WARN Refused reserved pin name=worker-x86_64-linux13042026/10/01 10:13:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13052026/10/01 10:13:59 INFO Received create pin request method=POST path=/api/pins/my-app13062026/10/01 10:13:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1307--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.87s)13082026/10/01 10:13:59 OK 20251218171726_add_pins.sql (1.98ms)1309=== CONT TestGetExistingObjectsLocksRows1310--- PASS: TestCreatePin_ReservedPins (0.87s)1311=== CONT TestRegisterCompletedObjectNeedsPendingRow13122026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)13132026-10-01 10:13:59.339 UTC [705] ERROR: relation "goose_db_version" does not exist at character 3613142026-10-01 10:13:59.339 UTC [705] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13152026-10-01 10:13:59.339 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3613162026-10-01 10:13:59.339 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13172026-10-01 10:13:59.339 UTC [706] ERROR: relation "goose_db_version" does not exist at character 3613182026-10-01 10:13:59.339 UTC [706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13192026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.87ms)13202026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (3.19ms)13212026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures13222026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.33ms)13232026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000013242026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.8ms)13252026/10/01 10:13:59 OK 2_object_stats_trigger.sql (2.03ms)13262026/10/01 10:13:59 OK 20241026095416_initial_model.sql (10.26ms)13272026/10/01 10:13:59 OK 3_commit_push.sql (1.67ms)13282026/10/01 10:13:59 goose: up to current file version: 313292026/10/01 10:13:59 OK 20241026095416_initial_model.sql (10.09ms)13302026/10/01 10:13:59 OK 20241026095416_initial_model.sql (10.09ms)13312026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)13322026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)13332026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)13342026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.61ms)13352026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.24ms)13362026/10/01 10:13:59 OK 20251218171726_add_pins.sql (4.47ms)13372026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=013382026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)13392026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)13402026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)13412026/10/01 10:13:59 WARN Force mode enabled - objects will be deleted immediately without grace period13422026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.43ms)13432026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.5ms)13442026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.95ms)13452026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.12ms)13462026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.81ms)13472026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.83ms)13482026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.34ms)13492026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000013502026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (3.79ms)13512026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000013522026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (3.71ms)13532026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000013542026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.89ms)13552026/10/01 10:13:59 OK 2_object_stats_trigger.sql (783.81µs)13562026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.85ms)13572026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.93ms)13582026/10/01 10:13:59 OK 3_commit_push.sql (796.84µs)13592026/10/01 10:13:59 goose: up to current file version: 313602026/10/01 10:13:59 OK 2_object_stats_trigger.sql (876.49µs)13612026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures13622026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.34ms)13632026/10/01 10:13:59 OK 3_commit_push.sql (1.37ms)13642026/10/01 10:13:59 goose: up to current file version: 313652026/10/01 10:13:59 OK 3_commit_push.sql (858.81µs)13662026/10/01 10:13:59 goose: up to current file version: 313672026/10/01 10:13:59 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=013682026/10/01 10:13:59 INFO Vacuumed table table=pending_closures13692026/10/01 10:13:59 INFO Vacuumed table table=pending_objects13702026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures13712026/10/01 10:13:59 INFO Vacuumed table table=multipart_uploads13722026/10/01 10:13:59 INFO Vacuumed table table=closures13732026/10/01 10:13:59 INFO Vacuumed table table=objects13742026/10/01 10:13:59 INFO Received cleanup request method=DELETE path=/api/pending_closures13752026/10/01 10:13:59 INFO Received complete push request method=POST path=/api/pushes/2/complete13762026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures1377--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.95s)1378=== CONT TestClientPushesUseOnePush13792026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures13802026-10-01 10:13:59.424 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3613812026-10-01 10:13:59.424 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13822026-10-01 10:13:59.424 UTC [712] ERROR: relation "goose_db_version" does not exist at character 3613832026-10-01 10:13:59.424 UTC [712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13842026/10/01 10:13:59 OK 20241026095416_initial_model.sql (8.29ms)13852026/10/01 10:13:59 OK 20241026095416_initial_model.sql (8.96ms)13862026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)13872026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)13882026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.26ms)13892026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.75ms)13902026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (2.79ms)13912026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.36ms)13922026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)13932026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (1.54ms)13942026/10/01 10:13:59 OK 20260905000000_add_claims.sql (2.6ms)13952026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.52ms)13962026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000013972026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.2ms)13982026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.03ms)13992026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.31ms)14002026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.74ms)14012026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000014022026/10/01 10:13:59 OK 3_commit_push.sql (1.55ms)14032026/10/01 10:13:59 goose: up to current file version: 314042026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.2ms)1405--- PASS: TestObjectStatsTrigger (0.87s)1406=== CONT TestFailedS3DeleteKeepsTombstone14072026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.25ms)14082026/10/01 10:13:59 OK 3_commit_push.sql (1.23ms)14092026/10/01 10:13:59 goose: up to current file version: 31410=== RUN TestPush_RejectsBadRequests/no_roots1411=== PAUSE TestPush_RejectsBadRequests/no_roots1412=== RUN TestPush_RejectsBadRequests/no_objects1413=== PAUSE TestPush_RejectsBadRequests/no_objects1414=== RUN TestPush_RejectsBadRequests/bad_root1415=== PAUSE TestPush_RejectsBadRequests/bad_root1416=== RUN TestPush_RejectsBadRequests/root_not_in_objects1417=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1418=== CONT TestForceGCDuringPushOffersSweptObject1419=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1420=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1421=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1422=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1423=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection14242026-10-01 10:13:59.492 UTC [717] ERROR: relation "goose_db_version" does not exist at character 3614252026-10-01 10:13:59.492 UTC [717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14262026/10/01 10:13:59 OK 20241026095416_initial_model.sql (8.33ms)14272026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)14282026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.44ms)14292026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)14302026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.57ms)14312026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.53ms)14322026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures14332026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.48ms)14342026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000014352026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.27ms)14362026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.53ms)14372026/10/01 10:13:59 OK 3_commit_push.sql (1.35ms)14382026/10/01 10:13:59 goose: up to current file version: 314392026/10/01 10:13:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14402026/10/01 10:13:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14412026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures14422026/10/01 10:13:59 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LjM1YTkxNjU4LWJlZTctNDI3ZS04YzExLWYwODFlZTQ2ZjllZHgxNzkwODQ5NjM5MDMxNzQxMzEx parts=1014432026/10/01 10:13:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14442026-10-01 10:13:59.563 UTC [735] ERROR: relation "goose_db_version" does not exist at character 3614452026-10-01 10:13:59.563 UTC [735] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026/10/01 10:13:59 INFO Completed upload id=114472026/10/01 10:13:59 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014482026-10-01 10:13:59.569 UTC [736] ERROR: relation "goose_db_version" does not exist at character 3614492026-10-01 10:13:59.569 UTC [736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14502026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures14512026/10/01 10:13:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures14522026/10/01 10:13:59 OK 20241026095416_initial_model.sql (7.48ms)14532026/10/01 10:13:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LjE0ZGVjZTFjLTBhNjQtNGVjYy05ZWYxLTAyZTE2YmU0M2EyMXgxNzkwODQ5NjM5MDU1MzY3NDU1 parts=1014542026/10/01 10:13:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14552026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)1456--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.99s)1457=== CONT TestGCSweepDeliversEachKeyOnce14582026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.68ms)14592026/10/01 10:13:59 INFO Completed upload id=114602026/10/01 10:13:59 OK 20241026095416_initial_model.sql (7.39ms)14612026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (2.51ms)14622026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures14632026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=014642026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)14652026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.49ms)14662026/10/01 10:13:59 OK 20260905000000_add_claims.sql (4.53ms)14672026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures14682026/10/01 10:13:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14692026/10/01 10:13:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1470--- PASS: TestService_NativeMTLS (0.68s)1471=== CONT TestTombstonedObjectOfferedWithoutWaiting14722026/10/01 10:13:59 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=014732026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)14742026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (3.19ms)14752026/10/01 10:13:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14762026/10/01 10:13:59 WARN Found objects in DB but missing from S3, will re-upload count=114772026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.55ms)1478--- PASS: TestService_verifyS3Integrity (1.14s)14792026/10/01 10:13:59 goose: successfully migrated database to version: 202609231200001480=== CONT TestGCSweepSkipsPendingObjects14812026/10/01 10:13:59 OK 20260905000000_add_claims.sql (2.93ms)14822026/10/01 10:13:59 INFO Vacuumed table table=pending_closures14832026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.45ms)14842026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3.6ms)14852026/10/01 10:13:59 INFO Vacuumed table table=pending_objects14862026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.93ms)14872026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.03ms)14882026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000014892026/10/01 10:13:59 INFO Vacuumed table table=multipart_uploads14902026/10/01 10:13:59 OK 3_commit_push.sql (2.18ms)14912026/10/01 10:13:59 goose: up to current file version: 314922026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3.28ms)14932026/10/01 10:13:59 INFO Vacuumed table table=closures14942026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.61ms)14952026/10/01 10:13:59 INFO Vacuumed table table=objects14962026/10/01 10:13:59 OK 3_commit_push.sql (1.59ms)14972026/10/01 10:13:59 goose: up to current file version: 314982026/10/01 10:13:59 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001499--- PASS: TestService_createPendingClosureHandler (1.17s)1500=== CONT TestDeduplicatedObjectsRecordedAsPending15012026/10/01 10:13:59 INFO Received cleanup request method=DELETE path=/api/pending_closures15022026/10/01 10:13:59 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15032026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=115042026/10/01 10:13:59 INFO Received cleanup request method=DELETE path=/api/pending_closures15052026/10/01 10:13:59 INFO Aborted multipart uploads count=1 kept=01506--- PASS: TestMetricsInventory (0.72s)1507=== CONT TestPushDedupSurvivesConcurrentGC1508--- PASS: TestMultipartCleanup (0.98s)1509=== CONT TestGCMetrics15102026/10/01 10:13:59 WARN readiness check failed error="closed pool"1511--- PASS: TestService_readinessHandler (0.66s)1512=== CONT TestGCBugBareHashReferences15132026-10-01 10:13:59.684 UTC [752] ERROR: relation "goose_db_version" does not exist at character 3615142026-10-01 10:13:59.684 UTC [752] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1515=== NAME TestNARDeduplicationMetadataUploadBug1516 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3995465456/001/store/cjy27mhpnpm38991yjzghsqdbj8p5dmh-file1.txt15172026-10-01 10:13:59.696 UTC [770] ERROR: relation "goose_db_version" does not exist at character 3615182026-10-01 10:13:59.696 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15192026-10-01 10:13:59.700 UTC [771] ERROR: relation "goose_db_version" does not exist at character 3615202026-10-01 10:13:59.700 UTC [771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15212026/10/01 10:13:59 OK 20241026095416_initial_model.sql (10.95ms)15222026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)1523--- PASS: TestService_healthCheckHandler (0.60s)1524=== CONT TestLeadEndsOnShutdown15252026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.83ms)15262026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)15272026/10/01 10:13:59 OK 20241026095416_initial_model.sql (9.32ms)15282026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.19ms)15292026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)15302026/10/01 10:13:59 OK 20241026095416_initial_model.sql (18.76ms)15312026/10/01 10:13:59 OK 20251218171726_add_pins.sql (13.4ms)15322026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (14.24ms)15332026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (4.59ms)15342026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.55ms)15352026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000015362026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)15372026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.81ms)15382026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3.06ms)15392026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.55ms)15402026/10/01 10:13:59 OK 2_object_stats_trigger.sql (2.55ms)15412026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (3.04ms)15422026/10/01 10:13:59 OK 3_commit_push.sql (2.17ms)15432026/10/01 10:13:59 goose: up to current file version: 315442026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)15452026-10-01 10:13:59.740 UTC [792] ERROR: relation "goose_db_version" does not exist at character 3615462026-10-01 10:13:59.740 UTC [792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15472026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.38ms)15482026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000015492026/10/01 10:13:59 OK 20260905000000_add_claims.sql (4.06ms)15502026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3ms)15512026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (3.2ms)15522026/10/01 10:13:59 OK 2_object_stats_trigger.sql (2.27ms)1553--- PASS: TestGCEndsOnShutdown (0.55s)1554=== CONT TestLeadElectsOneAndHandsOver15552026/10/01 10:13:59 OK 3_commit_push.sql (1.88ms)15562026/10/01 10:13:59 goose: up to current file version: 315572026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (3.13ms)15582026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000015592026/10/01 10:13:59 OK 1_commit_pending_closure.sql (3.42ms)15602026/10/01 10:13:59 OK 2_object_stats_trigger.sql (2.66ms)15612026/10/01 10:13:59 OK 3_commit_push.sql (2.2ms)15622026/10/01 10:13:59 goose: up to current file version: 315632026/10/01 10:13:59 OK 20241026095416_initial_model.sql (12.59ms)15642026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)15652026/10/01 10:13:59 OK 20251218171726_add_pins.sql (5.59ms)15662026-10-01 10:13:59.774 UTC [813] ERROR: relation "goose_db_version" does not exist at character 3615672026-10-01 10:13:59.774 UTC [813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15682026/10/01 10:13:59 INFO Received push request method=POST path=/api/pushes15692026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (10.6ms)15702026-10-01 10:13:59.783 UTC [814] ERROR: relation "goose_db_version" does not exist at character 3615712026-10-01 10:13:59.783 UTC [814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15722026/10/01 10:13:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15732026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.89ms)15742026/10/01 10:13:59 INFO Uploading cjy27mhpnpm38991yjzghsqdbj8p5dmh-file1.txt (160B)15752026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (3.43ms)15762026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (3.04ms)15772026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000015782026/10/01 10:13:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15792026/10/01 10:13:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15802026/10/01 10:13:59 WARN Failed to register uploaded object key=cjy27mhpnpm38991yjzghsqdbj8p5dmh.ls error="server returned 404: 404 page not found\n"15812026/10/01 10:13:59 INFO Signed narinfos id=1 count=115822026/10/01 10:13:59 INFO Uploading 1 narinfos15832026/10/01 10:13:59 OK 20241026095416_initial_model.sql (9.46ms)15842026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.58ms)15852026-10-01 10:13:59.794 UTC [815] ERROR: relation "goose_db_version" does not exist at character 3615862026-10-01 10:13:59.794 UTC [815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15872026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)15882026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.43ms)15892026/10/01 10:13:59 OK 3_commit_push.sql (1.46ms)15902026/10/01 10:13:59 goose: up to current file version: 315912026/10/01 10:13:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15922026/10/01 10:13:59 WARN Failed to register uploaded object key=cjy27mhpnpm38991yjzghsqdbj8p5dmh.narinfo error="server returned 404: 404 page not found\n"15932026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.06ms)15942026/10/01 10:13:59 OK 20241026095416_initial_model.sql (9.21ms)15952026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)15962026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)15972026/10/01 10:13:59 OK 20251218171726_add_pins.sql (4.13ms)15982026/10/01 10:13:59 INFO Upload complete. (74ms)15992026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.8ms)1600=== NAME TestNARDeduplicationMetadataUploadBug1601 metadata_upload_test.go:54: Retrieved narinfo from S3:1602 StorePath: /build/TestNARDeduplicationMetadataUploadBug3995465456/001/store/cjy27mhpnpm38991yjzghsqdbj8p5dmh-file1.txt1603 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1604 Compression: zstd1605 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1606 NarSize: 1601607 References: 1608 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16092026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (1.96ms)16102026/10/01 10:13:59 OK 20241026095416_initial_model.sql (8.91ms)16112026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.88ms)16122026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000016132026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)1614 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1615 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1616 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16172026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)16182026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.51ms)16192026/10/01 10:13:59 OK 2_object_stats_trigger.sql (941.46µs)16202026/10/01 10:13:59 OK 20251218171726_add_pins.sql (4.45ms)16212026/10/01 10:13:59 OK 3_commit_push.sql (2.82ms)16222026/10/01 10:13:59 goose: up to current file version: 316232026/10/01 10:13:59 OK 20260905000000_add_claims.sql (5.28ms)16242026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.35ms)16252026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (12.68ms)16262026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (10.15ms)16272026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000016282026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=016292026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.07ms)16302026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures16312026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.04ms)16322026/10/01 10:13:59 WARN Force mode enabled - objects will be deleted immediately without grace period16332026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.34ms)16342026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.51ms)16352026/10/01 10:13:59 OK 3_commit_push.sql (2.68ms)16362026/10/01 10:13:59 goose: up to current file version: 316372026/10/01 10:13:59 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=016382026-10-01 10:13:59.836 UTC [820] ERROR: relation "goose_db_version" does not exist at character 3616392026-10-01 10:13:59.836 UTC [820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16402026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (1.86ms)16412026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000016422026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.27ms)16432026/10/01 10:13:59 INFO Vacuumed table table=pending_closures16442026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.19ms)16452026/10/01 10:13:59 OK 3_commit_push.sql (1.16ms)16462026/10/01 10:13:59 goose: up to current file version: 316472026/10/01 10:13:59 INFO Vacuumed table table=pending_objects16482026/10/01 10:13:59 INFO Vacuumed table table=multipart_uploads16492026/10/01 10:13:59 INFO Vacuumed table table=closures16502026/10/01 10:13:59 INFO Vacuumed table table=objects1651 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3995465456/001/store/2grqwn272nn53h1dd07935dmac52bjhr-file2.txt16522026/10/01 10:13:59 OK 20241026095416_initial_model.sql (7.36ms)16532026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)1654--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.62s)1655=== CONT TestResolveDBConnectionString1656=== RUN TestResolveDBConnectionString/flag_wins1657=== PAUSE TestResolveDBConnectionString/flag_wins1658=== RUN TestResolveDBConnectionString/file_when_flag_empty1659=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1660=== RUN TestResolveDBConnectionString/missing_file_is_an_error1661=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1662=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1663=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1664=== RUN TestResolveDBConnectionString/nothing_configured1665=== PAUSE TestResolveDBConnectionString/nothing_configured1666=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock16672026/10/01 10:13:59 OK 20251218171726_add_pins.sql (2.66ms)16682026-10-01 10:13:59.854 UTC [839] ERROR: relation "goose_db_version" does not exist at character 3616692026-10-01 10:13:59.854 UTC [839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16702026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)16712026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.15ms)16722026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (1.65ms)1673=== NAME TestOrphanedObjectsGC1674 orphaned_objects_gc_test.go:290: GC Test Summary:1675 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1676 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1677 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1678 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1679 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1680--- PASS: TestOrphanedObjectsGC (1.28s)1681=== CONT TestClientFallsBackToClosures16822026/10/01 10:13:59 INFO Aborted multipart uploads count=0 kept=016832026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.33ms)16842026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000016852026/10/01 10:13:59 OK 20241026095416_initial_model.sql (6.84ms)16862026/10/01 10:13:59 OK 1_commit_pending_closure.sql (1.68ms)16872026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)16882026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.06ms)16892026/10/01 10:13:59 WARN Force mode enabled - objects will be deleted immediately without grace period16902026/10/01 10:13:59 OK 3_commit_push.sql (1.33ms)16912026/10/01 10:13:59 goose: up to current file version: 316922026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.13ms)16932026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)16942026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.65ms)16952026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (2.15ms)1696--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.55s)1697=== CONT TestCacheStatsHandler16982026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (6.45ms)16992026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000017002026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.66ms)17012026/10/01 10:13:59 OK 2_object_stats_trigger.sql (839.07µs)17022026/10/01 10:13:59 OK 3_commit_push.sql (588.23µs)17032026/10/01 10:13:59 goose: up to current file version: 317042026/10/01 10:13:59 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=017052026/10/01 10:13:59 INFO Vacuumed table table=pending_closures17062026/10/01 10:13:59 INFO Vacuumed table table=pending_objects17072026/10/01 10:13:59 INFO Vacuumed table table=multipart_uploads17082026/10/01 10:13:59 INFO Vacuumed table table=closures17092026/10/01 10:13:59 INFO Vacuumed table table=objects1710--- PASS: TestSweepRechecksPendingAfterLocking (0.67s)1711=== CONT TestPinProtectsFromGC17122026/10/01 10:13:59 INFO Received push request method=POST path=/api/pushes17132026/10/01 10:13:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1714--- PASS: TestGetExistingObjectsLocksRows (0.60s)1715=== CONT TestClientSharedPathCommittedMidPush17162026/10/01 10:13:59 WARN Failed to register uploaded object key=2grqwn272nn53h1dd07935dmac52bjhr.ls error="server returned 404: 404 page not found\n"17172026/10/01 10:13:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17182026/10/01 10:13:59 INFO Signed narinfos id=2 count=117192026/10/01 10:13:59 INFO Uploading 1 narinfos17202026/10/01 10:13:59 INFO Received complete push request method=POST path=/api/pushes/2/complete17212026/10/01 10:13:59 WARN Failed to register uploaded object key=2grqwn272nn53h1dd07935dmac52bjhr.narinfo error="server returned 404: 404 page not found\n"17222026/10/01 10:13:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17232026/10/01 10:13:59 INFO Upload complete. (52ms)1724=== NAME TestNARDeduplicationMetadataUploadBug1725 metadata_upload_test.go:76: Retrieved narinfo from S3:1726 StorePath: /build/TestNARDeduplicationMetadataUploadBug3995465456/001/store/2grqwn272nn53h1dd07935dmac52bjhr-file2.txt1727 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1728 Compression: zstd1729 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1730 NarSize: 1601731 References: 1732 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1733 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1734 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1735 {"version":1,"root":{"type":"regular","size":44}}17362026-10-01 10:13:59.946 UTC [893] ERROR: relation "goose_db_version" does not exist at character 3617372026-10-01 10:13:59.946 UTC [893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1738--- PASS: TestNARDeduplicationMetadataUploadBug (0.98s)1739=== CONT TestClientWithDependencies17402026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures17412026/10/01 10:13:59 OK 20241026095416_initial_model.sql (15.93ms)17422026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)17432026/10/01 10:13:59 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LmJlMzRmMTdmLWQ1NzAtNGE3OS05NmI5LWE1ZDg3NTIwY2VhOHgxNzkwODQ5NjM5MzYwMjg2OTc5 parts=1217442026/10/01 10:13:59 INFO Received uploads request method=POST path=/api/pending_closures17452026/10/01 10:13:59 OK 20251218171726_add_pins.sql (3.08ms)1746--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.52s)1747=== CONT TestClientMultipleUploads17482026-10-01 10:13:59.977 UTC [913] ERROR: relation "goose_db_version" does not exist at character 3617492026-10-01 10:13:59.977 UTC [913] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17502026/10/01 10:13:59 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)17512026/10/01 10:13:59 OK 20260905000000_add_claims.sql (3.83ms)17522026/10/01 10:13:59 OK 20260920000000_drop_claims.sql (4.73ms)17532026/10/01 10:13:59 OK 20260923120000_add_pushes.sql (2.06ms)17542026/10/01 10:13:59 goose: successfully migrated database to version: 2026092312000017552026/10/01 10:13:59 OK 1_commit_pending_closure.sql (2.53ms)17562026-10-01 10:13:59.991 UTC [917] ERROR: relation "goose_db_version" does not exist at character 3617572026-10-01 10:13:59.991 UTC [917] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17582026/10/01 10:13:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17592026/10/01 10:13:59 OK 2_object_stats_trigger.sql (1.9ms)17602026/10/01 10:13:59 OK 3_commit_push.sql (2.04ms)17612026/10/01 10:13:59 goose: up to current file version: 317622026/10/01 10:13:59 OK 20241026095416_initial_model.sql (9.56ms)17632026/10/01 10:13:59 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)17642026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures17652026/10/01 10:14:00 OK 20251218171726_add_pins.sql (4.46ms)17662026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)17672026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.41ms)17682026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)17692026-10-01 10:14:00.009 UTC [918] ERROR: relation "goose_db_version" does not exist at character 3617702026-10-01 10:14:00.009 UTC [918] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17712026/10/01 10:14:00 OK 20260905000000_add_claims.sql (2.96ms)17722026/10/01 10:14:00 OK 20251218171726_add_pins.sql (4.59ms)17732026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (4.11ms)17742026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.16ms)17752026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000017762026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)17772026/10/01 10:14:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LmUwNDVlNGQzLTA1ZTUtNDNmZi1hYzY4LWUxMjI0NzQyMjVlMHgxNzkwODQ5NjM5NDE5ODQ4NTM4 parts=1217782026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures17792026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.44ms)17802026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.56ms)17812026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.56ms)17822026/10/01 10:14:00 OK 3_commit_push.sql (1.07ms)17832026/10/01 10:14:00 goose: up to current file version: 317842026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.24ms)17852026/10/01 10:14:00 OK 20241026095416_initial_model.sql (8.77ms)17862026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures17872026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)17882026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.34ms)17892026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000017902026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.05ms)17912026/10/01 10:14:00 OK 20251218171726_add_pins.sql (2.8ms)17922026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.17ms)17932026/10/01 10:14:00 OK 3_commit_push.sql (1.1ms)17942026/10/01 10:14:00 goose: up to current file version: 317952026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)17962026/10/01 10:14:00 OK 20260905000000_add_claims.sql (2.75ms)17972026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.74ms)17982026-10-01 10:14:00.038 UTC [936] ERROR: relation "goose_db_version" does not exist at character 3617992026-10-01 10:14:00.038 UTC [936] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.09ms)18012026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000018022026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.72ms)18032026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.36ms)18042026/10/01 10:14:00 OK 3_commit_push.sql (1.33ms)18052026/10/01 10:14:00 goose: up to current file version: 318062026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=018072026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=018082026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period18092026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures18102026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period18112026/10/01 10:14:00 OK 20241026095416_initial_model.sql (19.72ms)18122026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)1813--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.48s)1814=== CONT TestClientIntegration18152026/10/01 10:14:00 OK 20251218171726_add_pins.sql (2.4ms)18162026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)18172026/10/01 10:14:00 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."18182026/10/01 10:14:00 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."18192026/10/01 10:14:00 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=01820--- PASS: TestFailedS3DeleteKeepsTombstone (0.62s)1821=== CONT TestClientErrorHandling1822=== RUN TestClientErrorHandling/InvalidStorePath1823=== PAUSE TestClientErrorHandling/InvalidStorePath1824=== RUN TestClientErrorHandling/InvalidAuthToken1825=== PAUSE TestClientErrorHandling/InvalidAuthToken1826=== RUN TestClientErrorHandling/ServerNotAvailable1827=== PAUSE TestClientErrorHandling/ServerNotAvailable18282026-10-01 10:14:00.075 UTC [956] ERROR: relation "goose_db_version" does not exist at character 3618292026-10-01 10:14:00.075 UTC [956] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1830=== CONT TestClientCADerivations18312026/10/01 10:14:00 OK 20260905000000_add_claims.sql (2.45ms)18322026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures18332026/10/01 10:14:00 INFO Vacuumed table table=pending_closures18342026/10/01 10:14:00 INFO Vacuumed table table=pending_objects18352026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads18362026/10/01 10:14:00 INFO Vacuumed table table=closures18372026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (1.61ms)18382026-10-01 10:14:00.077 UTC [958] ERROR: relation "goose_db_version" does not exist at character 3618392026-10-01 10:14:00.077 UTC [958] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18402026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.33ms)18412026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000018422026/10/01 10:14:00 INFO Vacuumed table table=objects1843--- PASS: TestGCSweepDeliversEachKeyOnce (0.50s)1844=== CONT TestService_AuthMiddleware_OIDC18452026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.01ms)18462026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.19ms)18472026/10/01 10:14:00 OK 3_commit_push.sql (1.23ms)18482026/10/01 10:14:00 goose: up to current file version: 318492026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.17ms)18502026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)18512026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.78ms)18522026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)18532026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.02ms)18542026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=018552026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures18562026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period18572026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.44ms)18582026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)18592026/10/01 10:14:00 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=018602026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)18612026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.15ms)18622026/10/01 10:14:00 OK 20260905000000_add_claims.sql (2.46ms)18632026/10/01 10:14:00 INFO Vacuumed table table=pending_closures18642026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.06ms)18652026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (1.79ms)18662026/10/01 10:14:00 INFO Vacuumed table table=pending_objects18672026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads18682026/10/01 10:14:00 INFO Vacuumed table table=closures18692026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.95ms)18702026/10/01 10:14:00 goose: successfully migrated database to version: 202609231200001871--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.48s)1872=== CONT TestCacheConfigHandler1873=== RUN TestCacheConfigHandler/full_config,_no_issuer1874=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1875=== RUN TestCacheConfigHandler/no_cache_url_configured1876=== PAUSE TestCacheConfigHandler/no_cache_url_configured1877=== RUN TestCacheConfigHandler/no_signing_keys1878=== PAUSE TestCacheConfigHandler/no_signing_keys1879=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator18802026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.91ms)1881=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator18822026/10/01 10:14:00 goose: successfully migrated database to version: 202609231200001883=== CONT TestService_ReadScope_PublicByDefault18842026/10/01 10:14:00 INFO Vacuumed table table=objects18852026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.61ms)18862026/10/01 10:14:00 OK 2_object_stats_trigger.sql (679.96µs)18872026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.44ms)18882026/10/01 10:14:00 OK 3_commit_push.sql (691.43µs)18892026/10/01 10:14:00 goose: up to current file version: 318902026/10/01 10:14:00 OK 2_object_stats_trigger.sql (645.72µs)18912026/10/01 10:14:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40931/oidc18922026/10/01 10:14:00 OK 3_commit_push.sql (1.95ms)18932026/10/01 10:14:00 goose: up to current file version: 31894--- PASS: TestGCSweepSkipsPendingObjects (0.53s)1895=== CONT TestService_RequireScope_OIDC18962026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes18972026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures18982026/10/01 10:14:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18992026/10/01 10:14:00 INFO Uploading 9g5w9l7wwhy4ip230q5il4iwcgr13i53-b (216B)19002026/10/01 10:14:00 INFO Uploading 0f32y182ai6zmizvd8rvlffx3q2939kv-shared-dep (136B)19012026/10/01 10:14:00 WARN Failed to register uploaded object key=9g5w9l7wwhy4ip230q5il4iwcgr13i53.ls error="server returned 404: 404 page not found\n"19022026/10/01 10:14:00 WARN Failed to register uploaded object key=62xwxw1y3p7j8cnn6a6wgrjpwpq138kk.ls error="server returned 404: 404 page not found\n"19032026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1w0za0s3n8rvv4la2gva5gdbrhx027770lqn3rc96lpy164vpbbb.nar.zst error="server returned 404: 404 page not found\n"19042026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19052026/10/01 10:14:00 WARN Failed to register uploaded object key=0f32y182ai6zmizvd8rvlffx3q2939kv.ls error="server returned 404: 404 page not found\n"19062026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19072026/10/01 10:14:00 INFO Signed narinfos id=1 count=319082026/10/01 10:14:00 INFO Uploading 3 narinfos19092026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=019102026/10/01 10:14:00 WARN Failed to register uploaded object key=9g5w9l7wwhy4ip230q5il4iwcgr13i53.narinfo error="server returned 404: 404 page not found\n"19112026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete19122026/10/01 10:14:00 WARN Failed to register uploaded object key=0f32y182ai6zmizvd8rvlffx3q2939kv.narinfo error="server returned 404: 404 page not found\n"19132026/10/01 10:14:00 WARN Failed to register uploaded object key=62xwxw1y3p7j8cnn6a6wgrjpwpq138kk.narinfo error="server returned 404: 404 page not found\n"19142026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period19152026/10/01 10:14:00 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=019162026/10/01 10:14:00 INFO Upload complete. (63ms)1917=== NAME TestClientPushesUseOnePush19182026/10/01 10:14:00 INFO Vacuumed table table=pending_closures1919 client_pushes_test.go:97: Retrieved narinfo from S3:1920 StorePath: /build/TestClientPushesUseOnePush1476311666/001/store/0f32y182ai6zmizvd8rvlffx3q2939kv-shared-dep1921 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1922 Compression: zstd1923 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821924 NarSize: 1361925 References: 1926 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19272026/10/01 10:14:00 INFO Vacuumed table table=pending_objects19282026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads19292026/10/01 10:14:00 INFO Vacuumed table table=closures19302026/10/01 10:14:00 INFO Vacuumed table table=objects1931 client_pushes_test.go:97: Retrieved narinfo from S3:1932 StorePath: /build/TestClientPushesUseOnePush1476311666/001/store/62xwxw1y3p7j8cnn6a6wgrjpwpq138kk-a1933 URL: nar/1w0za0s3n8rvv4la2gva5gdbrhx027770lqn3rc96lpy164vpbbb.nar.zst1934 Compression: zstd1935 NarHash: sha256:1w0za0s3n8rvv4la2gva5gdbrhx027770lqn3rc96lpy164vpbbb1936 NarSize: 2161937 References: /build/TestClientPushesUseOnePush1476311666/001/store/0f32y182ai6zmizvd8rvlffx3q2939kv-shared-dep1938 CA: text:sha256:1rlhcrp2mvyb2hpx08frf5hh40gf377c4lb8068d003l4n154knx1939 client_pushes_test.go:97: Retrieved narinfo from S3:1940 StorePath: /build/TestClientPushesUseOnePush1476311666/001/store/9g5w9l7wwhy4ip230q5il4iwcgr13i53-b1941 URL: nar/1w0za0s3n8rvv4la2gva5gdbrhx027770lqn3rc96lpy164vpbbb.nar.zst1942 Compression: zstd1943 NarHash: sha256:1w0za0s3n8rvv4la2gva5gdbrhx027770lqn3rc96lpy164vpbbb1944 NarSize: 2161945 References: /build/TestClientPushesUseOnePush1476311666/001/store/0f32y182ai6zmizvd8rvlffx3q2939kv-shared-dep1946 CA: text:sha256:1rlhcrp2mvyb2hpx08frf5hh40gf377c4lb8068d003l4n154knx1947--- PASS: TestGCMetrics (0.50s)1948=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1949--- PASS: TestClientPushesUseOnePush (0.76s)1950=== CONT TestReadProxyHead19512026-10-01 10:14:00.176 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 3619522026-10-01 10:14:00.176 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19532026/10/01 10:14:00 INFO lead: acquired remote=192.0.2.1:123419542026/10/01 10:14:00 INFO lead: released remote=192.0.2.1:12341955--- PASS: TestLeadEndsOnShutdown (0.48s)1956=== CONT TestService_ReadAuthMiddleware19572026/10/01 10:14:00 INFO lead: acquired remote=192.0.2.1:123419582026/10/01 10:14:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37991/oidc19592026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=019602026/10/01 10:14:00 OK 20241026095416_initial_model.sql (12.24ms)19612026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)19622026-10-01 10:14:00.209 UTC [1012] ERROR: relation "goose_db_version" does not exist at character 3619632026-10-01 10:14:00.209 UTC [1012] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19642026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.8ms)19652026/10/01 10:14:00 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=019662026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)1967--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.75s)1968=== CONT TestPush_CompleteCommitsEveryRoot19692026/10/01 10:14:00 INFO Vacuumed table table=pending_closures19702026/10/01 10:14:00 INFO Vacuumed table table=pending_objects19712026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads19722026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.89ms)19732026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.8ms)19742026/10/01 10:14:00 INFO Vacuumed table table=closures19752026-10-01 10:14:00.226 UTC [1017] ERROR: relation "goose_db_version" does not exist at character 3619762026-10-01 10:14:00.226 UTC [1017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19772026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.75ms)19782026-10-01 10:14:00.226 UTC [1018] ERROR: relation "goose_db_version" does not exist at character 3619792026-10-01 10:14:00.226 UTC [1018] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19802026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000019812026/10/01 10:14:00 OK 20241026095416_initial_model.sql (10.38ms)19822026/10/01 10:14:00 INFO Vacuumed table table=objects19832026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3ms)19842026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)19852026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.53ms)19862026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=019872026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period19882026/10/01 10:14:00 OK 3_commit_push.sql (2.26ms)19892026/10/01 10:14:00 goose: up to current file version: 319902026/10/01 10:14:00 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=019912026/10/01 10:14:00 OK 20251218171726_add_pins.sql (5.88ms)19922026/10/01 10:14:00 INFO Vacuumed table table=pending_closures19932026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5.45ms)19942026/10/01 10:14:00 INFO Vacuumed table table=pending_objects19952026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads19962026/10/01 10:14:00 INFO Vacuumed table table=closures19972026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.37ms)19982026/10/01 10:14:00 INFO Vacuumed table table=objects1999--- PASS: TestPushDedupSurvivesConcurrentGC (0.59s)2000=== CONT TestReadRedirectKeepsNarinfoProxied20012026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.71ms)20022026/10/01 10:14:00 OK 20241026095416_initial_model.sql (12.95ms)20032026/10/01 10:14:00 OK 20241026095416_initial_model.sql (13.15ms)20042026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.29ms)20052026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000020062026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)20072026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)20082026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.74ms)20092026/10/01 10:14:00 OK 20251218171726_add_pins.sql (14.64ms)20102026/10/01 10:14:00 OK 2_object_stats_trigger.sql (17.21ms)20112026/10/01 10:14:00 OK 20251218171726_add_pins.sql (17.81ms)20122026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)20132026/10/01 10:14:00 OK 3_commit_push.sql (1.13ms)20142026/10/01 10:14:00 goose: up to current file version: 320152026/10/01 10:14:00 OK 20260905000000_add_claims.sql (6.51ms)20162026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (8.45ms)20172026-10-01 10:14:00.282 UTC [1023] ERROR: relation "goose_db_version" does not exist at character 3620182026-10-01 10:14:00.282 UTC [1023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20192026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.91ms)20202026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.81ms)20212026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.34ms)20222026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000020232026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.77ms)20242026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (5.85ms)20252026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.75ms)20262026/10/01 10:14:00 OK 3_commit_push.sql (1.33ms)20272026/10/01 10:14:00 goose: up to current file version: 320282026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.84ms)20292026/10/01 10:14:00 goose: successfully migrated database to version: 202609231200002030--- PASS: TestCacheStatsHandler (0.41s)2031=== CONT TestReadRedirectNar20322026-10-01 10:14:00.294 UTC [1040] ERROR: relation "goose_db_version" does not exist at character 3620332026-10-01 10:14:00.294 UTC [1040] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20342026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.12ms)20352026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.46ms)20362026/10/01 10:14:00 OK 3_commit_push.sql (1.38ms)20372026/10/01 10:14:00 goose: up to current file version: 320382026/10/01 10:14:00 OK 20241026095416_initial_model.sql (10.91ms)20392026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)20402026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.43ms)20412026/10/01 10:14:00 OK 20241026095416_initial_model.sql (8.52ms)20422026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)20432026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)20442026/10/01 10:14:00 OK 20251218171726_add_pins.sql (4.37ms)20452026-10-01 10:14:00.315 UTC [1044] ERROR: relation "goose_db_version" does not exist at character 3620462026-10-01 10:14:00.315 UTC [1044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20472026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.6ms)20482026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.48ms)20492026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)20502026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.69ms)20512026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000020522026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.23ms)20532026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.2ms)20542026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.42ms)20552026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.74ms)20562026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.49ms)20572026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000020582026/10/01 10:14:00 OK 3_commit_push.sql (2.3ms)20592026/10/01 10:14:00 goose: up to current file version: 320602026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.22ms)20612026-10-01 10:14:00.332 UTC [1047] ERROR: relation "goose_db_version" does not exist at character 3620622026-10-01 10:14:00.332 UTC [1047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20632026-10-01 10:14:00.338 UTC [1049] ERROR: relation "goose_db_version" does not exist at character 3620642026-10-01 10:14:00.338 UTC [1049] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20652026/10/01 10:14:00 OK 2_object_stats_trigger.sql (12.14ms)20662026/10/01 10:14:00 OK 20241026095416_initial_model.sql (23.41ms)20672026/10/01 10:14:00 OK 3_commit_push.sql (3.61ms)20682026/10/01 10:14:00 goose: up to current file version: 320692026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)2070--- PASS: TestPushWaitsForSweepHoldingRow (1.12s)2071=== CONT TestPush_OverlappingRootsStoreOneRowPerKey20722026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.94ms)20732026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5.83ms)20742026/10/01 10:14:00 OK 20241026095416_initial_model.sql (11.64ms)20752026/10/01 10:14:00 INFO lead: released remote=192.0.2.1:123420762026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)20772026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.2ms)20782026/10/01 10:14:00 OK 20251218171726_add_pins.sql (4.44ms)20792026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.56ms)20802026/10/01 10:14:00 OK 20241026095416_initial_model.sql (17.44ms)20812026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.33ms)20822026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000020832026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)20842026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)20852026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.12ms)20862026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.13ms)20872026/10/01 10:14:00 OK 2_object_stats_trigger.sql (3.15ms)20882026/10/01 10:14:00 OK 20251218171726_add_pins.sql (5.34ms)20892026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.6ms)20902026/10/01 10:14:00 OK 3_commit_push.sql (1.31ms)20912026/10/01 10:14:00 goose: up to current file version: 320922026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.92ms)20932026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000020942026-10-01 10:14:00.376 UTC [1118] ERROR: relation "goose_db_version" does not exist at character 3620952026-10-01 10:14:00.376 UTC [1118] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20962026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)20972026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.12ms)20982026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.72ms)20992026/10/01 10:14:00 OK 3_commit_push.sql (2.2ms)21002026/10/01 10:14:00 goose: up to current file version: 321012026/10/01 10:14:00 OK 20260905000000_add_claims.sql (5.23ms)21022026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.18ms)2103=== NAME TestPinProtectsFromGC2104 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2402736408/001/store/ybid182av6y1dcnwfrfqkw8lizimbp56-pinned-file.txt2105 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2402736408/001/store/0d7ghi2yhmic2p9p7l1q97kgn5hsv3q7-unpinned-file.txt2106--- PASS: TestGCBugBareHashReferences (0.71s)2107=== CONT TestReadProxyDisabled21082026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.68ms)21092026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000021102026/10/01 10:14:00 OK 20241026095416_initial_model.sql (8.52ms)21112026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.91ms)21122026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)21132026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.8ms)21142026/10/01 10:14:00 OK 3_commit_push.sql (1.62ms)21152026/10/01 10:14:00 goose: up to current file version: 321162026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.41ms)21172026-10-01 10:14:00.399 UTC [1160] ERROR: relation "goose_db_version" does not exist at character 3621182026-10-01 10:14:00.399 UTC [1160] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21192026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)21202026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.36ms)21212026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.53ms)21222026/10/01 10:14:00 INFO lead: acquired remote=192.0.2.1:123421232026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.99ms)21242026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000021252026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.29ms)21262026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.47ms)21272026/10/01 10:14:00 OK 3_commit_push.sql (1.39ms)21282026/10/01 10:14:00 goose: up to current file version: 321292026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.22ms)21302026/10/01 10:14:00 INFO lead: released remote=192.0.2.1:12342131--- PASS: TestLeadElectsOneAndHandsOver (0.67s)2132=== CONT TestReadRedirectUsesPublicS3URL21332026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)21342026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.13ms)21352026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)21362026/10/01 10:14:00 OK 20260905000000_add_claims.sql (2.81ms)21372026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.06ms)21382026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.34ms)21392026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000021402026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.67ms)2141=== NAME TestClientMultipleUploads2142 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4191198624/001/store/bkr2zrm23smn01sk9yxiy0xlvrix7dsz-test-file-0.txt21432026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.36ms)21442026/10/01 10:14:00 OK 3_commit_push.sql (1.13ms)21452026/10/01 10:14:00 goose: up to current file version: 321462026-10-01 10:14:00.443 UTC [1254] ERROR: relation "goose_db_version" does not exist at character 3621472026-10-01 10:14:00.443 UTC [1254] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21482026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures2149=== NAME TestClientWithDependencies2150 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies358756011/001/store/bf5q7v5cy5sxyrllc3lxihk9hwz6kyw4-test-script2151=== NAME TestClientIntegration2152 client_integration_test.go:286: Created store path: /build/TestClientIntegration2239365489/002/store/yhv4n8x4522xfvrv2gmxwzlr8vjc3gr6-test-file.txt2153=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2154=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2155=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2156=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2157=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2158=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2159=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2160=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2161=== CONT TestReadProxyRootRedirectsToIndexHTML21622026/10/01 10:14:00 INFO Received uploads request method=POST path=/api/pending_closures21632026/10/01 10:14:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21642026/10/01 10:14:00 INFO Uploading x83gr0dlcdgv7mgmwbwvvcdici3slf65-shared-dep (136B)21652026/10/01 10:14:00 INFO Uploading 4gxl50s55kd4zn53gn9kmi2i8wbdz9wj-b (216B)21662026/10/01 10:14:00 OK 20241026095416_initial_model.sql (8.2ms)21672026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes21682026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)21692026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1d38j9b1sxv4ysw8dnwfnchd04ll2w1viwsg640rc4kp4aa6gw6k.nar.zst error="server returned 404: 404 page not found\n"21702026/10/01 10:14:00 WARN Failed to register uploaded object key=ip6342ak1ncnsjkvv1wafyhzlqwxw8hb.ls error="server returned 404: 404 page not found\n"21712026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21722026/10/01 10:14:00 WARN Failed to register uploaded object key=4gxl50s55kd4zn53gn9kmi2i8wbdz9wj.ls error="server returned 404: 404 page not found\n"21732026/10/01 10:14:00 WARN Failed to register uploaded object key=x83gr0dlcdgv7mgmwbwvvcdici3slf65.ls error="server returned 404: 404 page not found\n"2174=== NAME TestClientMultipleUploads21752026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2176 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4191198624/001/store/31y8yn0rcvyr02gmv8lmzpfzqxpwqdf5-test-file-1.txt21772026/10/01 10:14:00 INFO Signed narinfos id=1 count=221782026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21792026/10/01 10:14:00 INFO Signed narinfos id=2 count=221802026/10/01 10:14:00 INFO Uploading 4 narinfos21812026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.69ms)21822026/10/01 10:14:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21832026/10/01 10:14:00 INFO Uploading ybid182av6y1dcnwfrfqkw8lizimbp56-pinned-file.txt (128B)21842026/10/01 10:14:00 WARN Failed to register uploaded object key=x83gr0dlcdgv7mgmwbwvvcdici3slf65.narinfo error="server returned 404: 404 page not found\n"21852026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)21862026/10/01 10:14:00 WARN Failed to register uploaded object key=4gxl50s55kd4zn53gn9kmi2i8wbdz9wj.narinfo error="server returned 404: 404 page not found\n"21872026/10/01 10:14:00 WARN Failed to register uploaded object key=ip6342ak1ncnsjkvv1wafyhzlqwxw8hb.narinfo error="server returned 404: 404 page not found\n"21882026/10/01 10:14:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21892026/10/01 10:14:00 WARN Failed to register uploaded object key=x83gr0dlcdgv7mgmwbwvvcdici3slf65.narinfo error="server returned 404: 404 page not found\n"21902026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21912026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21922026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.1ms)21932026/10/01 10:14:00 WARN Failed to register uploaded object key=ybid182av6y1dcnwfrfqkw8lizimbp56.ls error="server returned 404: 404 page not found\n"21942026/10/01 10:14:00 INFO Signed narinfos id=1 count=121952026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes21962026/10/01 10:14:00 INFO Uploading 1 narinfos21972026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.69ms)21982026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete21992026/10/01 10:14:00 WARN Failed to register uploaded object key=ybid182av6y1dcnwfrfqkw8lizimbp56.narinfo error="server returned 404: 404 page not found\n"22002026/10/01 10:14:00 INFO Completed upload id=122012026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.27ms)22022026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000022032026/10/01 10:14:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2204--- PASS: TestService_ReadScope_PublicByDefault (0.38s)22052026/10/01 10:14:00 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)2206=== CONT TestReadProxyRangeRequest22072026/10/01 10:14:00 INFO Uploading 7p75pggd9wfv603sxljb30fmk09yjs6b-shared-dep (136B)22082026/10/01 10:14:00 INFO Uploading 3dpv7h6vl46df8js6mfp5i35w2iv3dsh-top (224B)2209=== NAME TestClientWithDependencies2210 client_integration_test.go:615: Found 1 dependencies (including self)22112026-10-01 10:14:00.486 UTC [1412] ERROR: relation "goose_db_version" does not exist at character 3622122026-10-01 10:14:00.486 UTC [1412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22132026/10/01 10:14:00 INFO Completed upload id=222142026/10/01 10:14:00 INFO Upload complete. (82ms)22152026/10/01 10:14:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22162026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.16ms)2217=== NAME TestClientFallsBackToClosures2218 client_pushes_test.go:112: Retrieved narinfo from S3:2219 StorePath: /build/TestClientFallsBackToClosures526538651/001/store/x83gr0dlcdgv7mgmwbwvvcdici3slf65-shared-dep2220 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2221 Compression: zstd2222 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822223 NarSize: 1362224 References: 2225 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22262026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22272026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.51ms)2228 client_pushes_test.go:112: Retrieved narinfo from S3:2229 StorePath: /build/TestClientFallsBackToClosures526538651/001/store/ip6342ak1ncnsjkvv1wafyhzlqwxw8hb-a2230 URL: nar/1d38j9b1sxv4ysw8dnwfnchd04ll2w1viwsg640rc4kp4aa6gw6k.nar.zst2231 Compression: zstd2232 NarHash: sha256:1d38j9b1sxv4ysw8dnwfnchd04ll2w1viwsg640rc4kp4aa6gw6k2233 NarSize: 2162234 References: /build/TestClientFallsBackToClosures526538651/001/store/x83gr0dlcdgv7mgmwbwvvcdici3slf65-shared-dep2235 CA: text:sha256:03jq8rxcwbdwdyg8a41dri78qhisv1880d7rdldzwq3y97m5lh4l22362026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/0kynw6w8r495wpbwcl8iglzl5zdih062x1jcn6k7cz11a8gn9r2i.nar.zst error="server returned 404: 404 page not found\n"22372026/10/01 10:14:00 WARN Failed to register uploaded object key=3dpv7h6vl46df8js6mfp5i35w2iv3dsh.ls error="server returned 404: 404 page not found\n"22382026/10/01 10:14:00 OK 3_commit_push.sql (1.56ms)22392026/10/01 10:14:00 goose: up to current file version: 32240 client_pushes_test.go:112: Retrieved narinfo from S3:2241 StorePath: /build/TestClientFallsBackToClosures526538651/001/store/4gxl50s55kd4zn53gn9kmi2i8wbdz9wj-b2242 URL: nar/1d38j9b1sxv4ysw8dnwfnchd04ll2w1viwsg640rc4kp4aa6gw6k.nar.zst2243 Compression: zstd22442026/10/01 10:14:00 WARN Failed to register uploaded object key=7p75pggd9wfv603sxljb30fmk09yjs6b.ls error="server returned 404: 404 page not found\n"2245 NarHash: sha256:1d38j9b1sxv4ysw8dnwfnchd04ll2w1viwsg640rc4kp4aa6gw6k2246 NarSize: 2162247 References: /build/TestClientFallsBackToClosures526538651/001/store/x83gr0dlcdgv7mgmwbwvvcdici3slf65-shared-dep22482026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2249 CA: text:sha256:03jq8rxcwbdwdyg8a41dri78qhisv1880d7rdldzwq3y97m5lh4l22502026/10/01 10:14:00 INFO Signed narinfos id=1 count=222512026/10/01 10:14:00 INFO Uploading 2 narinfos2252--- PASS: TestClientFallsBackToClosures (0.63s)2253=== CONT TestReadProxyConditionalGet22542026/10/01 10:14:00 WARN Failed to register uploaded object key=7p75pggd9wfv603sxljb30fmk09yjs6b.narinfo error="server returned 404: 404 page not found\n"22552026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete22562026/10/01 10:14:00 WARN Failed to register uploaded object key=3dpv7h6vl46df8js6mfp5i35w2iv3dsh.narinfo error="server returned 404: 404 page not found\n"22572026/10/01 10:14:00 INFO Upload complete. (72ms)22582026/10/01 10:14:00 OK 20241026095416_initial_model.sql (10.46ms)22592026/10/01 10:14:00 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LjdhMzU1NTZmLTIwNGMtNDgwMC1iNDVmLTVjNGViMGYyYTg5NXgxNzkwODQ5NjQwMDI4NzA2Njg1 error="Get \"http://127.0.0.1:1/bucket21/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"22602026/10/01 10:14:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Mzk1YWIzNTMtYjA0MS00MWI0LWE1NjMtNjdlNWU0MzMwYTY4LjgxYTA1OGNlLTE2NTktNGJhZC04ODQ3LWU0ODE0ZGI0NzAxN3gxNzkwODQ5NjQwMDIyMjY0Mzk5 parts=1222612026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)22622026/10/01 10:14:00 INFO Received cleanup request method=DELETE path=/api/pending_closures22632026/10/01 10:14:00 INFO Upload complete. (61ms)2264=== NAME TestClientSharedPathCommittedMidPush2265 client_integration_test.go:680: Retrieved narinfo from S3:2266 StorePath: /build/TestClientSharedPathCommittedMidPush2500222740/001/store/7p75pggd9wfv603sxljb30fmk09yjs6b-shared-dep2267 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2268 Compression: zstd2269 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822270 NarSize: 1362271 References: 2272 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22732026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.64ms)2274=== NAME TestClientMultipleUploads2275 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4191198624/001/store/xl9gd4aacs6nzw0zwavikp0dinnzw9sc-test-file-2.txt2276=== NAME TestClientSharedPathCommittedMidPush2277 client_integration_test.go:680: Retrieved narinfo from S3:2278 StorePath: /build/TestClientSharedPathCommittedMidPush2500222740/001/store/3dpv7h6vl46df8js6mfp5i35w2iv3dsh-top2279 URL: nar/0kynw6w8r495wpbwcl8iglzl5zdih062x1jcn6k7cz11a8gn9r2i.nar.zst2280 Compression: zstd2281 NarHash: sha256:0kynw6w8r495wpbwcl8iglzl5zdih062x1jcn6k7cz11a8gn9r2i2282 NarSize: 2242283 References: /build/TestClientSharedPathCommittedMidPush2500222740/001/store/7p75pggd9wfv603sxljb30fmk09yjs6b-shared-dep2284 CA: text:sha256:0935fqsk33jvn8pb86nzpn1zkgkm9v8p25dr9kvnvklv9nv26hvp22852026/10/01 10:14:00 INFO Aborted multipart uploads count=1 kept=022862026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)2287--- PASS: TestClientSharedPathCommittedMidPush (0.58s)2288=== CONT TestService_AuthMiddleware_MTLSProxyHeader2289--- PASS: TestRedundantMultipartUpload (1.93s)2290=== CONT TestReadProxyNarinfo22912026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.44ms)2292--- PASS: TestReadProxyHead (0.35s)2293=== CONT TestProxyHeadersOnlyTrustedOnSocket22942026-10-01 10:14:00.520 UTC [1453] ERROR: relation "goose_db_version" does not exist at character 3622952026-10-01 10:14:00.520 UTC [1453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22962026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.51ms)22972026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.19ms)22982026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000022992026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.06ms)23002026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.77ms)23012026/10/01 10:14:00 OK 3_commit_push.sql (2.14ms)23022026/10/01 10:14:00 goose: up to current file version: 323032026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2304=== NAME TestClientCADerivations2305 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations705385978/001/store/66s1bkxzx9lqb8j305s5mdvwnks0zgyr-ca-test23062026/10/01 10:14:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23072026/10/01 10:14:00 INFO Uploading yhv4n8x4522xfvrv2gmxwzlr8vjc3gr6-test-file.txt (152B)23082026/10/01 10:14:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"23092026/10/01 10:14:00 WARN mTLS auth: bound subjects configured but subject DN unavailable23102026/10/01 10:14:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2311--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.38s)2312=== CONT TestReadProxyInvalidPath23132026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"23142026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23152026/10/01 10:14:00 WARN Failed to register uploaded object key=yhv4n8x4522xfvrv2gmxwzlr8vjc3gr6.ls error="server returned 404: 404 page not found\n"23162026/10/01 10:14:00 INFO Signed narinfos id=1 count=123172026/10/01 10:14:00 INFO Uploading 1 narinfos23182026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete23192026/10/01 10:14:00 WARN Failed to register uploaded object key=yhv4n8x4522xfvrv2gmxwzlr8vjc3gr6.narinfo error="server returned 404: 404 page not found\n"23202026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes23212026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2322--- PASS: TestService_ReadAuthMiddleware (0.38s)2323=== CONT TestIsValidCachePath2324=== RUN TestIsValidCachePath/narinfo2325=== PAUSE TestIsValidCachePath/narinfo2326=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2327=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2328=== RUN TestIsValidCachePath/nar_zst2329=== PAUSE TestIsValidCachePath/nar_zst2330=== RUN TestIsValidCachePath/nar_xz2331=== PAUSE TestIsValidCachePath/nar_xz2332=== RUN TestIsValidCachePath/nar_bz22333=== PAUSE TestIsValidCachePath/nar_bz22334=== RUN TestIsValidCachePath/nar_uncompressed2335=== PAUSE TestIsValidCachePath/nar_uncompressed2336=== RUN TestIsValidCachePath/ls2337=== PAUSE TestIsValidCachePath/ls2338=== RUN TestIsValidCachePath/log2339=== PAUSE TestIsValidCachePath/log2340=== RUN TestIsValidCachePath/realisation2341=== PAUSE TestIsValidCachePath/realisation2342=== RUN TestIsValidCachePath/nix-cache-info2343=== PAUSE TestIsValidCachePath/nix-cache-info2344=== RUN TestIsValidCachePath/index.html23452026/10/01 10:14:00 OK 20241026095416_initial_model.sql (32.87ms)2346=== PAUSE TestIsValidCachePath/index.html2347=== RUN TestIsValidCachePath/traversal_parent2348=== PAUSE TestIsValidCachePath/traversal_parent2349=== RUN TestIsValidCachePath/traversal_in_middle2350=== PAUSE TestIsValidCachePath/traversal_in_middle2351=== RUN TestIsValidCachePath/invalid_char_e2352=== PAUSE TestIsValidCachePath/invalid_char_e2353=== RUN TestIsValidCachePath/invalid_char_u2354=== PAUSE TestIsValidCachePath/invalid_char_u2355=== RUN TestIsValidCachePath/random_path2356=== PAUSE TestIsValidCachePath/random_path2357=== RUN TestIsValidCachePath/empty2358=== PAUSE TestIsValidCachePath/empty2359=== RUN TestIsValidCachePath/leading_slash2360=== PAUSE TestIsValidCachePath/leading_slash2361=== RUN TestIsValidCachePath/wrong_extension2362=== PAUSE TestIsValidCachePath/wrong_extension2363=== RUN TestIsValidCachePath/short_hash2364=== PAUSE TestIsValidCachePath/short_hash2365=== CONT TestReadProxy40423662026/10/01 10:14:00 INFO Upload complete. (80ms)23672026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (4.1ms)23682026/10/01 10:14:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23692026/10/01 10:14:00 INFO Uploading 0d7ghi2yhmic2p9p7l1q97kgn5hsv3q7-unpinned-file.txt (128B)2370=== NAME TestClientCADerivations2371 client_ca_test.go:139: Found 1 dependencies (including self)23722026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.27ms)23732026/10/01 10:14:00 WARN Failed to register uploaded object key=0d7ghi2yhmic2p9p7l1q97kgn5hsv3q7.ls error="server returned 404: 404 page not found\n"23742026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"23752026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23762026/10/01 10:14:00 INFO Signed narinfos id=2 count=123772026/10/01 10:14:00 INFO Uploading 1 narinfos23782026/10/01 10:14:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23792026/10/01 10:14:00 INFO Uploading bf5q7v5cy5sxyrllc3lxihk9hwz6kyw4-test-script (136B)23802026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)23812026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/2/complete2382--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.72s)23832026/10/01 10:14:00 WARN Failed to register uploaded object key=0d7ghi2yhmic2p9p7l1q97kgn5hsv3q7.narinfo error="server returned 404: 404 page not found\n"2384=== CONT TestReadProxyNarStreaming23852026/10/01 10:14:00 WARN Failed to register uploaded object key=bf5q7v5cy5sxyrllc3lxihk9hwz6kyw4.ls error="server returned 404: 404 page not found\n"23862026/10/01 10:14:00 WARN Failed to register uploaded object key=log/ns1rkd7n2lfxj1hgqanq053bsl7xpq88-test-script.drv error="server returned 404: 404 page not found\n"23872026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23882026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"23892026/10/01 10:14:00 INFO Signed narinfos id=1 count=123902026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.5ms)23912026/10/01 10:14:00 INFO Uploading 1 narinfos23922026/10/01 10:14:00 INFO Upload complete. (50ms)23932026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes23942026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.84ms)23952026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete23962026/10/01 10:14:00 WARN Failed to register uploaded object key=bf5q7v5cy5sxyrllc3lxihk9hwz6kyw4.narinfo error="server returned 404: 404 page not found\n"23972026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.08ms)23982026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000023992026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.33ms)24002026/10/01 10:14:00 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)24012026/10/01 10:14:00 INFO Uploading xl9gd4aacs6nzw0zwavikp0dinnzw9sc-test-file-2.txt (160B)24022026/10/01 10:14:00 INFO Uploading 31y8yn0rcvyr02gmv8lmzpfzqxpwqdf5-test-file-1.txt (160B)24032026/10/01 10:14:00 INFO Uploading bkr2zrm23smn01sk9yxiy0xlvrix7dsz-test-file-0.txt (160B)24042026-10-01 10:14:00.590 UTC [1612] ERROR: relation "goose_db_version" does not exist at character 3624052026-10-01 10:14:00.590 UTC [1612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24062026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes24072026/10/01 10:14:00 OK 2_object_stats_trigger.sql (3.27ms)24082026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"24092026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"24102026/10/01 10:14:00 OK 3_commit_push.sql (2.47ms)24112026/10/01 10:14:00 goose: up to current file version: 324122026/10/01 10:14:00 WARN Failed to register uploaded object key=xl9gd4aacs6nzw0zwavikp0dinnzw9sc.ls error="server returned 404: 404 page not found\n"24132026/10/01 10:14:00 WARN Failed to register uploaded object key=bkr2zrm23smn01sk9yxiy0xlvrix7dsz.ls error="server returned 404: 404 page not found\n"24142026/10/01 10:14:00 WARN Failed to register uploaded object key=31y8yn0rcvyr02gmv8lmzpfzqxpwqdf5.ls error="server returned 404: 404 page not found\n"24152026/10/01 10:14:00 INFO Upload complete. (76ms)24162026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"24172026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24182026/10/01 10:14:00 INFO Signed narinfos id=1 count=324192026/10/01 10:14:00 INFO Uploading 3 narinfos2420=== NAME TestClientWithDependencies2421 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies358756011/001/store) requires matching store prefix24222026/10/01 10:14:00 WARN Failed to register uploaded object key=bkr2zrm23smn01sk9yxiy0xlvrix7dsz.narinfo error="server returned 404: 404 page not found\n"24232026/10/01 10:14:00 WARN Failed to register uploaded object key=xl9gd4aacs6nzw0zwavikp0dinnzw9sc.narinfo error="server returned 404: 404 page not found\n"24242026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete24252026/10/01 10:14:00 WARN Failed to register uploaded object key=31y8yn0rcvyr02gmv8lmzpfzqxpwqdf5.narinfo error="server returned 404: 404 page not found\n"2426--- PASS: TestClientWithDependencies (0.65s)2427=== CONT TestReadProxyNarinfoAlreadyDecompressed24282026/10/01 10:14:00 INFO All 1 paths already cached2429=== NAME TestClientIntegration2430 client_integration_test.go:312: Retrieved narinfo from S3:2431 StorePath: /build/TestClientIntegration2239365489/002/store/yhv4n8x4522xfvrv2gmxwzlr8vjc3gr6-test-file.txt2432 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2433 Compression: zstd2434 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12435 NarSize: 1522436 References: 2437 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12438 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2439 client_integration_test.go:313: Decompressed .ls content (64 bytes):2440 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2441 client_integration_test.go:316: Testing garbage collection...24422026-10-01 10:14:00.609 UTC [1665] ERROR: relation "goose_db_version" does not exist at character 3624432026-10-01 10:14:00.609 UTC [1665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24442026/10/01 10:14:00 OK 20241026095416_initial_model.sql (13.13ms)24452026/10/01 10:14:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures24462026/10/01 10:14:00 INFO Garbage collection started24472026/10/01 10:14:00 INFO Upload complete. (87ms)2448=== NAME TestClientMultipleUploads2449 client_integration_test.go:369: Uploaded 3 paths in 118.694999ms2450=== RUN TestService_RequireScope_OIDC/builder_may_write2451=== PAUSE TestService_RequireScope_OIDC/builder_may_write2452=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2453=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2454=== RUN TestService_RequireScope_OIDC/ops_may_admin2455=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2456=== RUN TestService_RequireScope_OIDC/ops_may_not_write2457=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2458=== RUN TestService_RequireScope_OIDC/reader_may_not_write2459=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write24602026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (24.48ms)2461=== RUN TestService_RequireScope_OIDC/static_token_may_admin2462=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2463=== RUN TestService_RequireScope_OIDC/static_token_may_write2464=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2465=== RUN TestService_RequireScope_OIDC/reader_may_read2466=== PAUSE TestService_RequireScope_OIDC/reader_may_read2467=== RUN TestService_RequireScope_OIDC/writer_implies_read2468=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2469=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2470=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2471=== CONT TestParseSingleRange2472=== RUN TestParseSingleRange/none2473=== PAUSE TestParseSingleRange/none2474=== RUN TestParseSingleRange/unknown_unit24752026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete2476=== PAUSE TestParseSingleRange/unknown_unit2477=== RUN TestParseSingleRange/multi-range_ignored2478=== PAUSE TestParseSingleRange/multi-range_ignored2479=== RUN TestParseSingleRange/malformed_no_dash2480=== PAUSE TestParseSingleRange/malformed_no_dash2481=== RUN TestParseSingleRange/malformed_both_empty2482=== PAUSE TestParseSingleRange/malformed_both_empty2483=== RUN TestParseSingleRange/malformed_end_before_start2484=== PAUSE TestParseSingleRange/malformed_end_before_start2485=== RUN TestParseSingleRange/closed2486=== PAUSE TestParseSingleRange/closed2487=== RUN TestParseSingleRange/open-ended2488=== PAUSE TestParseSingleRange/open-ended2489=== RUN TestParseSingleRange/end_clamped_to_size2490=== PAUSE TestParseSingleRange/end_clamped_to_size2491=== RUN TestParseSingleRange/suffix2492=== PAUSE TestParseSingleRange/suffix2493=== RUN TestParseSingleRange/suffix_exceeds_size2494=== PAUSE TestParseSingleRange/suffix_exceeds_size2495=== RUN TestParseSingleRange/single_byte2496=== PAUSE TestParseSingleRange/single_byte2497=== RUN TestParseSingleRange/start_past_EOF2498=== PAUSE TestParseSingleRange/start_past_EOF2499=== RUN TestParseSingleRange/start_far_past_EOF2500=== PAUSE TestParseSingleRange/start_far_past_EOF2501=== CONT TestPresentNotReportedWhileGCDeletesClosure2502--- PASS: TestClientMultipleUploads (0.66s)2503=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info25042026/10/01 10:14:00 INFO Received uploads request method=POST path=/2505=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key25062026/10/01 10:14:00 INFO Received complete multipart upload request method=POST path=/2507=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25082026/10/01 10:14:00 INFO Received request for more parts method=POST path=/2509=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25102026/10/01 10:14:00 INFO Received uploads request method=POST path=/2511--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2512 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2513 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2514 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2515 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2516=== CONT TestProxyWriteTimeout/narinfo2517=== CONT TestProxyWriteTimeout/unknown_size2518=== CONT TestProxyWriteTimeout/1_GiB_nar2519=== CONT TestProxyWriteTimeout/10_GiB_nar2520--- PASS: TestProxyWriteTimeout (0.13s)2521 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2522 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2523 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2524 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2525=== CONT TestIsValidUploadKey/narinfo2526=== CONT TestIsValidUploadKey/empty_key2527=== CONT TestIsValidUploadKey/absolute2528=== CONT TestIsValidUploadKey/traversal_nar2529=== CONT TestIsValidUploadKey/traversal2530=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2531=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2532=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2533=== CONT TestIsValidUploadKey/index.html25342026/10/01 10:14:00 OK 20251218171726_add_pins.sql (4.6ms)2535=== CONT TestIsValidUploadKey/nix-cache-info2536=== CONT TestIsValidUploadKey/realisation_plus_in_output2537=== CONT TestIsValidUploadKey/realisation2538=== CONT TestIsValidUploadKey/build_log_equals2539=== CONT TestIsValidUploadKey/build_log_question_mark2540=== CONT TestIsValidUploadKey/unknown_type2541=== CONT TestIsValidUploadKey/build_log_plus_in_name2542=== CONT TestIsValidUploadKey/build_log_home-manager_file2543=== CONT TestIsValidUploadKey/build_log2544=== CONT TestIsValidUploadKey/listing2545=== CONT TestIsValidUploadKey/nar_plain2546=== CONT TestIsValidUploadKey/nar_xz2547=== CONT TestIsValidUploadKey/nar_zst2548--- PASS: TestIsValidUploadKey (0.13s)2549 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2550 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2551 --- PASS: TestIsValidUploadKey/absolute (0.00s)2552 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2553 --- PASS: TestIsValidUploadKey/traversal (0.00s)2554 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2555 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2556 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2557 --- PASS: TestIsValidUploadKey/index.html (0.00s)2558 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2559 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2560 --- PASS: TestIsValidUploadKey/realisation (0.00s)2561 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2562 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2563 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2564 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2565 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2566 --- PASS: TestIsValidUploadKey/build_log (0.00s)2567 --- PASS: TestIsValidUploadKey/listing (0.00s)2568 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2569 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2570 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2571=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25722026/10/01 10:14:00 INFO Received request for more parts method=POST path=/25732026-10-01 10:14:00.644 UTC [1672] ERROR: relation "goose_db_version" does not exist at character 3625742026-10-01 10:14:00.644 UTC [1672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25752026/10/01 10:14:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures25762026/10/01 10:14:00 INFO Garbage collection started25772026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (7.17ms)2578--- PASS: TestReadRedirectKeepsNarinfoProxied (0.40s)2579=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25802026/10/01 10:14:00 INFO Received complete multipart upload request method=POST path=/25812026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=025822026/10/01 10:14:00 OK 20241026095416_initial_model.sql (18.3ms)2583--- PASS: TestPush_CompleteCommitsEveryRoot (0.44s)2584=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure25852026/10/01 10:14:00 INFO Received uploads request method=POST path=/25862026/10/01 10:14:00 OK 20260905000000_add_claims.sql (12.71ms)25872026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period25882026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (12.96ms)25892026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (13.93ms)25902026-10-01 10:14:00.679 UTC [1712] ERROR: relation "goose_db_version" does not exist at character 3625912026-10-01 10:14:00.679 UTC [1712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25922026-10-01 10:14:00.679 UTC [1713] ERROR: relation "goose_db_version" does not exist at character 3625932026-10-01 10:14:00.679 UTC [1713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25942026-10-01 10:14:00.679 UTC [1714] ERROR: relation "goose_db_version" does not exist at character 3625952026-10-01 10:14:00.679 UTC [1714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25962026/10/01 10:14:00 INFO Aborted multipart uploads count=0 kept=025972026/10/01 10:14:00 OK 20251218171726_add_pins.sql (16.5ms)25982026/10/01 10:14:00 OK 20241026095416_initial_model.sql (22.54ms)2599=== CONT TestServerTLSConfig/no_client_CA2600=== CONT TestServerTLSConfig/not_a_PEM_file2601=== CONT TestServerTLSConfig/missing_CA_file2602--- PASS: TestServerTLSConfig (0.00s)2603 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2604 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2605 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2606=== CONT TestPush_RejectsBadRequests/no_roots26072026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2608=== CONT TestPush_RejectsBadRequests/bad_root26092026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2610=== CONT TestPush_RejectsBadRequests/root_not_in_objects26112026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2612=== CONT TestPush_RejectsBadRequests/no_objects26132026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2614=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2615--- PASS: TestPush_RejectsBadRequests (0.99s)2616 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2617 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2618 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2619 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)26202026/10/01 10:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period26212026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (15.64ms)26222026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000026232026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes26242026-10-01 10:14:00.701 UTC [1733] ERROR: relation "goose_db_version" does not exist at character 3626252026-10-01 10:14:00.701 UTC [1733] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2626=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check26272026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (22.66ms)26282026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (22.47ms)26292026/10/01 10:14:00 OK 1_commit_pending_closure.sql (19.24ms)26302026/10/01 10:14:00 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=026312026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.82ms)26322026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.94ms)26332026/10/01 10:14:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26342026/10/01 10:14:00 INFO Uploading 66s1bkxzx9lqb8j305s5mdvwnks0zgyr-ca-test (144B)26352026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.73ms)26362026/10/01 10:14:00 OK 3_commit_push.sql (2.29ms)26372026/10/01 10:14:00 goose: up to current file version: 326382026/10/01 10:14:00 INFO Vacuumed table table=pending_closures26392026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)26402026-10-01 10:14:00.716 UTC [1737] ERROR: relation "goose_db_version" does not exist at character 3626412026-10-01 10:14:00.716 UTC [1737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26422026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (4.96ms)26432026/10/01 10:14:00 WARN Failed to register uploaded object key=66s1bkxzx9lqb8j305s5mdvwnks0zgyr.ls error="server returned 404: 404 page not found\n"26442026/10/01 10:14:00 WARN Failed to register uploaded object key=log/569mjrdiagi7k1w14mrfcbk8y09h7lzy-ca-test.drv error="server returned 404: 404 page not found\n"26452026/10/01 10:14:00 OK 20241026095416_initial_model.sql (11.09ms)26462026/10/01 10:14:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26472026/10/01 10:14:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"26482026/10/01 10:14:00 INFO Signed narinfos id=1 count=126492026/10/01 10:14:00 INFO Uploading 1 narinfos26502026/10/01 10:14:00 OK 20241026095416_initial_model.sql (11.63ms)26512026/10/01 10:14:00 OK 20241026095416_initial_model.sql (12.15ms)2652--- PASS: TestReadRedirectNar (0.43s)2653=== CONT TestResolveDBConnectionString/flag_wins2654=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2655=== CONT TestResolveDBConnectionString/nothing_configured2656=== CONT TestResolveDBConnectionString/missing_file_is_an_error2657=== CONT TestResolveDBConnectionString/file_when_flag_empty26582026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.2ms)2659=== CONT TestClientErrorHandling/InvalidStorePath26602026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.41ms)26612026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000026622026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)26632026/10/01 10:14:00 INFO Vacuumed table table=pending_objects2664--- PASS: TestResolveDBConnectionString (0.00s)2665 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2666 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2667 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2668 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2669 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)26702026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads26712026/10/01 10:14:00 OK 20241026095416_initial_model.sql (11.1ms)26722026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)26732026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)26742026-10-01 10:14:00.723 UTC [1738] ERROR: relation "goose_db_version" does not exist at character 3626752026-10-01 10:14:00.723 UTC [1738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26762026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.09ms)26772026/10/01 10:14:00 INFO Received complete push request method=POST path=/api/pushes/1/complete26782026/10/01 10:14:00 WARN Failed to register uploaded object key=66s1bkxzx9lqb8j305s5mdvwnks0zgyr.narinfo error="server returned 404: 404 page not found\n"26792026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.57ms)26802026/10/01 10:14:00 INFO Vacuumed table table=closures26812026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.58ms)26822026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)26832026/10/01 10:14:00 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=026842026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.7ms)26852026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.69ms)26862026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000026872026/10/01 10:14:00 INFO Vacuumed table table=objects26882026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.86ms)26892026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.95ms)26902026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.3ms)26912026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4ms)26922026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.9ms)26932026/10/01 10:14:00 OK 3_commit_push.sql (2.13ms)26942026/10/01 10:14:00 goose: up to current file version: 326952026/10/01 10:14:00 INFO Vacuumed table table=pending_closures26962026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5ms)26972026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.34ms)26982026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)26992026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)27002026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.55ms)27012026/10/01 10:14:00 OK 3_commit_push.sql (2.38ms)27022026/10/01 10:14:00 goose: up to current file version: 327032026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.49ms)27042026/10/01 10:14:00 OK 20241026095416_initial_model.sql (12.15ms)27052026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.88ms)27062026/10/01 10:14:00 INFO Vacuumed table table=pending_objects27072026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.05ms)27082026/10/01 10:14:00 OK 20260905000000_add_claims.sql (4.6ms)27092026/10/01 10:14:00 INFO Vacuumed table table=multipart_uploads27102026/10/01 10:14:00 INFO Upload complete. (129ms)27112026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)27122026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.78ms)27132026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.86ms)27142026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.55ms)27152026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027162026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.75ms)27172026/10/01 10:14:00 INFO Received push request method=POST path=/api/pushes2718=== NAME TestClientCADerivations2719 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations705385978/001/store/66s1bkxzx9lqb8j305s5mdvwnks0zgyr-ca-test2720 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2721 Compression: zstd2722 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2723 NarSize: 1442724 References: 2725 Deriver: /build/TestClientCADerivations705385978/001/store/569mjrdiagi7k1w14mrfcbk8y09h7lzy-ca-test.drv2726 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2727 client_ca_test.go:185: Checking for realisation files in S3...27282026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.32ms)27292026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027302026/10/01 10:14:00 OK 20241026095416_initial_model.sql (11.98ms)27312026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.4ms)27322026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027332026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.12ms)2734 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2735 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache27362026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.96ms)27372026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.47ms)27382026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027392026/10/01 10:14:00 INFO Vacuumed table table=closures27402026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)27412026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.62ms)27422026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.23ms)27432026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.46ms)27442026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3.18ms)27452026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.21ms)27462026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.17ms)27472026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)27482026/10/01 10:14:00 OK 3_commit_push.sql (2.25ms)27492026/10/01 10:14:00 goose: up to current file version: 327502026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.16ms)27512026/10/01 10:14:00 OK 2_object_stats_trigger.sql (2.07ms)27522026/10/01 10:14:00 INFO Vacuumed table table=objects27532026/10/01 10:14:00 OK 3_commit_push.sql (2.16ms)27542026/10/01 10:14:00 goose: up to current file version: 327552026/10/01 10:14:00 OK 3_commit_push.sql (1.63ms)27562026/10/01 10:14:00 goose: up to current file version: 327572026/10/01 10:14:00 OK 3_commit_push.sql (1.69ms)27582026/10/01 10:14:00 goose: up to current file version: 327592026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)27602026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.86ms)27612026-10-01 10:14:00.751 UTC [1742] ERROR: relation "goose_db_version" does not exist at character 3627622026-10-01 10:14:00.751 UTC [1742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27632026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.08ms)27642026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.71ms)27652026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.32ms)27662026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.1ms)27672026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027682026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (3.35ms)27692026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027702026/10/01 10:14:00 OK 1_commit_pending_closure.sql (3ms)27712026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.59ms)27722026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.66ms)27732026/10/01 10:14:00 OK 3_commit_push.sql (1.75ms)27742026/10/01 10:14:00 goose: up to current file version: 327752026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.61ms)2776--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.42s)2777=== CONT TestClientErrorHandling/ServerNotAvailable27782026/10/01 10:14:00 OK 3_commit_push.sql (1.27ms)27792026/10/01 10:14:00 goose: up to current file version: 32780--- PASS: TestReadProxyDisabled (0.38s)2781=== CONT TestClientErrorHandling/InvalidAuthToken27822026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.74ms)27832026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)27842026/10/01 10:14:00 OK 20251218171726_add_pins.sql (2.87ms)27852026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)27862026-10-01 10:14:00.783 UTC [1748] ERROR: relation "goose_db_version" does not exist at character 3627872026-10-01 10:14:00.783 UTC [1748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27882026/10/01 10:14:00 OK 20260905000000_add_claims.sql (19.14ms)27892026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (3.02ms)27902026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.07ms)27912026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000027922026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.98ms)27932026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.95ms)27942026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.32ms)27952026/10/01 10:14:00 OK 3_commit_push.sql (1.73ms)27962026/10/01 10:14:00 goose: up to current file version: 327972026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)2798--- PASS: TestReadRedirectUsesPublicS3URL (0.40s)2799=== CONT TestCacheConfigHandler/full_config,_no_issuer2800=== CONT TestCacheConfigHandler/no_signing_keys2801=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2802=== CONT TestCacheConfigHandler/no_cache_url_configured2803--- PASS: TestCacheConfigHandler (0.00s)2804 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2805 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2806 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2807 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2808=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token28092026/10/01 10:14:00 OK 20251218171726_add_pins.sql (4.83ms)2810=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected28112026/10/01 10:14:00 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]2812=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2813=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected28142026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)28152026/10/01 10:14:00 WARN Authentication failed token_preview=eyJhbGciOi...ZfeNtQOCEw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2816=== CONT TestIsValidCachePath/narinfo2817=== CONT TestIsValidCachePath/index.html2818=== CONT TestIsValidCachePath/short_hash2819=== CONT TestIsValidCachePath/invalid_char_u2820=== CONT TestIsValidCachePath/invalid_char_e2821=== CONT TestIsValidCachePath/traversal_in_middle2822=== CONT TestIsValidCachePath/traversal_parent2823=== CONT TestIsValidCachePath/random_path28242026-10-01 10:14:00.821 UTC [1804] ERROR: relation "goose_db_version" does not exist at character 3628252026-10-01 10:14:00.821 UTC [1804] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2826=== CONT TestIsValidCachePath/wrong_extension2827=== CONT TestIsValidCachePath/leading_slash2828=== CONT TestIsValidCachePath/empty2829=== CONT TestIsValidCachePath/nar_uncompressed2830=== CONT TestIsValidCachePath/log2831=== CONT TestIsValidCachePath/ls2832=== CONT TestIsValidCachePath/realisation2833=== CONT TestIsValidCachePath/nix-cache-info2834=== CONT TestIsValidCachePath/nar_xz2835=== CONT TestIsValidCachePath/nar_bz22836=== CONT TestIsValidCachePath/nar_zst2837=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2838=== CONT TestService_RequireScope_OIDC/builder_may_write2839--- PASS: TestIsValidCachePath (0.00s)2840 --- PASS: TestIsValidCachePath/narinfo (0.00s)2841 --- PASS: TestIsValidCachePath/index.html (0.00s)2842 --- PASS: TestIsValidCachePath/short_hash (0.00s)2843 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2844 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2845 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2846 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2847 --- PASS: TestIsValidCachePath/random_path (0.00s)2848 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2849 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2850 --- PASS: TestIsValidCachePath/empty (0.00s)2851 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2852 --- PASS: TestIsValidCachePath/log (0.00s)2853 --- PASS: TestIsValidCachePath/ls (0.00s)2854 --- PASS: TestIsValidCachePath/realisation (0.00s)2855 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2856 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2857 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2858 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2859 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2860--- PASS: TestService_AuthMiddleware_OIDC (0.38s)2861 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2862 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2863 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2864 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)28652026-10-01 10:14:00.822 UTC [1783] ERROR: relation "goose_db_version" does not exist at character 3628662026-10-01 10:14:00.822 UTC [1783] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28672026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.38ms)2868=== CONT TestService_RequireScope_OIDC/static_token_may_admin2869=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2870=== CONT TestService_RequireScope_OIDC/writer_implies_read2871=== CONT TestService_RequireScope_OIDC/reader_may_read2872=== CONT TestService_RequireScope_OIDC/static_token_may_write2873=== CONT TestService_RequireScope_OIDC/ops_may_not_write2874=== CONT TestService_RequireScope_OIDC/ops_may_admin2875=== CONT TestService_RequireScope_OIDC/builder_may_not_admin28762026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (1.92ms)2877=== CONT TestService_RequireScope_OIDC/reader_may_not_write2878=== CONT TestParseSingleRange/none2879=== CONT TestParseSingleRange/start_past_EOF2880=== CONT TestParseSingleRange/single_byte2881=== CONT TestParseSingleRange/suffix_exceeds_size2882=== CONT TestParseSingleRange/suffix2883=== CONT TestParseSingleRange/start_far_past_EOF2884=== CONT TestParseSingleRange/end_clamped_to_size2885=== CONT TestParseSingleRange/open-ended2886=== CONT TestParseSingleRange/closed2887=== CONT TestParseSingleRange/malformed_end_before_start2888=== CONT TestParseSingleRange/malformed_both_empty2889=== CONT TestParseSingleRange/malformed_no_dash2890=== CONT TestParseSingleRange/multi-range_ignored2891=== CONT TestParseSingleRange/unknown_unit2892--- PASS: TestParseSingleRange (0.00s)2893 --- PASS: TestParseSingleRange/none (0.00s)2894 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2895 --- PASS: TestParseSingleRange/single_byte (0.00s)2896 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2897 --- PASS: TestParseSingleRange/suffix (0.00s)2898 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2899 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2900 --- PASS: TestParseSingleRange/open-ended (0.00s)2901 --- PASS: TestParseSingleRange/closed (0.00s)2902 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2903 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2904 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2905 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2906 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2907--- PASS: TestService_RequireScope_OIDC (0.52s)2908 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2909 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2910 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2911 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2912 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2913 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2914 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2915 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2916 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2917 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)29182026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.94ms)29192026/10/01 10:14:00 goose: successfully migrated database to version: 202609231200002920--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.37s)29212026/10/01 10:14:00 OK 1_commit_pending_closure.sql (2.39ms)29222026/10/01 10:14:00 OK 2_object_stats_trigger.sql (708.38µs)29232026/10/01 10:14:00 OK 3_commit_push.sql (1.15ms)29242026/10/01 10:14:00 goose: up to current file version: 329252026-10-01 10:14:00.831 UTC [1910] ERROR: relation "goose_db_version" does not exist at character 3629262026-10-01 10:14:00.831 UTC [1910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29272026/10/01 10:14:00 OK 20241026095416_initial_model.sql (7.8ms)29282026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)29292026/10/01 10:14:00 OK 20251218171726_add_pins.sql (2.87ms)29302026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)29312026/10/01 10:14:00 OK 20241026095416_initial_model.sql (14.41ms)29322026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.42ms)29332026/10/01 10:14:00 OK 20241026095416_initial_model.sql (9.17ms)29342026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)29352026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (972.27µs)29362026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.05ms)29372026/10/01 10:14:00 OK 20251218171726_add_pins.sql (2.46ms)29382026/10/01 10:14:00 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/present29392026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (2.02ms)29402026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000029412026/10/01 10:14:00 OK 20251218171726_add_pins.sql (3.72ms)29422026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.97ms)29432026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)29442026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.51ms)2945--- PASS: TestReadProxyRangeRequest (0.37s)29462026/10/01 10:14:00 OK 3_commit_push.sql (1.77ms)29472026/10/01 10:14:00 goose: up to current file version: 329482026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (5.51ms)29492026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.27ms)29502026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.07ms)29512026/10/01 10:14:00 OK 20260905000000_add_claims.sql (3.55ms)29522026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.36ms)29532026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000029542026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.73ms)29552026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (2.56ms)29562026/10/01 10:14:00 OK 2_object_stats_trigger.sql (712.58µs)29572026/10/01 10:14:00 OK 3_commit_push.sql (1ms)29582026/10/01 10:14:00 goose: up to current file version: 329592026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (1.81ms)29602026/10/01 10:14:00 goose: successfully migrated database to version: 202609231200002961=== NAME TestClientCADerivations29622026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.87ms)2963 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2964 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2965 error: binary cache 's3://bucket58?endpoint=http://localhost:36867®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations705385978/001/store'2966 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 129672026/10/01 10:14:00 OK 2_object_stats_trigger.sql (1.05ms)29682026/10/01 10:14:00 OK 3_commit_push.sql (813.49µs)29692026/10/01 10:14:00 goose: up to current file version: 329702026-10-01 10:14:00.874 UTC [1997] ERROR: relation "goose_db_version" does not exist at character 3629712026-10-01 10:14:00.874 UTC [1997] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2972--- PASS: TestClientCADerivations (0.80s)2973--- PASS: TestReadProxyConditionalGet (0.38s)29742026/10/01 10:14:00 OK 20241026095416_initial_model.sql (6.48ms)29752026/10/01 10:14:00 OK 20251210153512_drop_unused_gin_index.sql (893.84µs)29762026/10/01 10:14:00 OK 20251218171726_add_pins.sql (1.6ms)29772026/10/01 10:14:00 OK 20260628120000_add_object_size_and_stats.sql (2.14ms)29782026/10/01 10:14:00 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3122614122/001/proxy.sock29792026/10/01 10:14:00 INFO Starting HTTP server address=127.0.0.1:3790929802026/10/01 10:14:00 WARN mTLS auth: subject not in bound subjects subject="CN=someone"29812026/10/01 10:14:00 INFO Shutdown signal received, draining in-flight requests timeout=10s29822026/10/01 10:14:00 OK 20260905000000_add_claims.sql (2.17ms)2983--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.37s)29842026/10/01 10:14:00 OK 20260920000000_drop_claims.sql (1.39ms)29852026/10/01 10:14:00 OK 20260923120000_add_pushes.sql (977.27µs)29862026/10/01 10:14:00 goose: successfully migrated database to version: 2026092312000029872026/10/01 10:14:00 OK 1_commit_pending_closure.sql (1.37ms)29882026/10/01 10:14:00 OK 2_object_stats_trigger.sql (637.44µs)29892026/10/01 10:14:00 OK 3_commit_push.sql (630.34µs)29902026/10/01 10:14:00 goose: up to current file version: 32991--- PASS: TestReadProxyNarinfo (0.40s)2992--- PASS: TestReadProxyInvalidPath (0.39s)29932026/10/01 10:14:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.632278ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2994--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.44s)2995=== NAME TestOrphanedObjectsGCStressTest2996 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2997--- PASS: TestReadProxy404 (0.43s)2998=== NAME TestOrphanedObjectsGCStressTest2999 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion3000--- PASS: TestReadProxyNarStreaming (0.42s)3001--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.42s)30022026/10/01 10:14:01 INFO Received uploads request method=POST path=/api/pending_closures30032026/10/01 10:14:01 INFO Aborted multipart uploads count=0 kept=030042026/10/01 10:14:01 WARN Force mode enabled - objects will be deleted immediately without grace period30052026/10/01 10:14:01 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=030062026/10/01 10:14:01 INFO Vacuumed table table=pending_closures30072026/10/01 10:14:01 INFO Vacuumed table table=pending_objects30082026/10/01 10:14:01 INFO Vacuumed table table=multipart_uploads30092026/10/01 10:14:01 INFO Vacuumed table table=closures30102026/10/01 10:14:01 INFO Vacuumed table table=objects30112026/10/01 10:14:01 INFO Received uploads request method=POST path=/api/pending_closures30122026/10/01 10:14:01 INFO Aborted multipart uploads count=0 kept=030132026/10/01 10:14:01 WARN Force mode enabled - objects will be deleted immediately without grace period30142026/10/01 10:14:01 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=030152026/10/01 10:14:01 INFO Vacuumed table table=pending_closures30162026/10/01 10:14:01 INFO Vacuumed table table=pending_objects30172026/10/01 10:14:01 INFO Vacuumed table table=multipart_uploads30182026/10/01 10:14:01 INFO Vacuumed table table=closures30192026/10/01 10:14:01 INFO Vacuumed table table=objects3020--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3021 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.40s)3022 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.47s)30232026/10/01 10:14:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.160793ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3024--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)3025 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)3026 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)3027 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.73s)30282026/10/01 10:14:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"3029=== NAME TestOrphanedObjectsGCStressTest3030 orphaned_objects_gc_test.go:509: Stress test completed successfully:3031 orphaned_objects_gc_test.go:510: - Active objects preserved: 203032 orphaned_objects_gc_test.go:511: - Objects deleted: 2103033 orphaned_objects_gc_test.go:512: - Total GC'd: 2103034--- PASS: TestOrphanedObjectsGCStressTest (2.94s)30352026/10/01 10:14:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"3036--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.91s)30372026/10/01 10:14:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=806.113842ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30382026/10/01 10:14:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.440689836s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30392026/10/01 10:14:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=030402026/10/01 10:14:02 INFO Received create pin request method=POST path=/api/pins/myapp30412026/10/01 10:14:02 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2402736408/001/store/ybid182av6y1dcnwfrfqkw8lizimbp56-pinned-file.txt narinfo_key=ybid182av6y1dcnwfrfqkw8lizimbp56.narinfo30422026/10/01 10:14:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures30432026/10/01 10:14:02 INFO Garbage collection started30442026/10/01 10:14:02 INFO Aborted multipart uploads count=0 kept=030452026/10/01 10:14:02 WARN Force mode enabled - objects will be deleted immediately without grace period30462026/10/01 10:14:02 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=030472026/10/01 10:14:02 INFO Vacuumed table table=pending_closures30482026/10/01 10:14:02 INFO Vacuumed table table=pending_objects30492026/10/01 10:14:02 INFO Vacuumed table table=multipart_uploads30502026/10/01 10:14:02 INFO Vacuumed table table=closures30512026/10/01 10:14:02 INFO Vacuumed table table=objects30522026/10/01 10:14:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03053=== NAME TestClientIntegration3054 client_integration_test.go:323: Objects in database after GC:3055 client_integration_test.go:323: Successfully deleted all objects with GC --force3056--- PASS: TestClientIntegration (2.59s)30572026/10/01 10:14:03 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-config30582026/10/01 10:14:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.292196ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30592026/10/01 10:14:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.718917ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30602026/10/01 10:14:04 WARN Rate limiter enabled after throttle name=s3-test rate=530612026/10/01 10:14:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3062=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3063 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103064 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003065--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.76s)30662026/10/01 10:14:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.207111ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3067=== NAME TestPinProtectsFromGC3068 client_integration_test.go:840: Pin successfully protected closure from garbage collection3069--- PASS: TestPinProtectsFromGC (4.74s)30702026/10/01 10:14:05 INFO Aborted multipart uploads count=1 kept=030712026/10/01 10:14:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.57868747s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30722026/10/01 10:14:05 INFO Received cleanup request method=DELETE path=/api/pending_closures30732026/10/01 10:14:05 INFO Aborted multipart uploads count=1 kept=03074--- PASS: TestPendingCleanupUsesOneCutoff (6.83s)30752026/10/01 10:14:06 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"30762026/10/01 10:14:07 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-config30772026/10/01 10:14:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.214539ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30782026/10/01 10:14:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=426.264785ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30792026/10/01 10:14:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=727.031769ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30802026/10/01 10:14:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.484291543s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30812026/10/01 10:14:09 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_closures30822026/10/01 10:14:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.559598ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30832026/10/01 10:14:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.45798ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30842026/10/01 10:14:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.471657ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30852026/10/01 10:14:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.655596792s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3086--- PASS: TestClientErrorHandling (0.00s)3087 --- PASS: TestClientErrorHandling/InvalidStorePath (0.41s)3088 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.65s)3089 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.38s)3090PASS30912026-10-01 10:14:13.481 UTC [128] LOG: received smart shutdown request30922026-10-01 10:14:13.486 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 130932026-10-01 10:14:13.492 UTC [133] LOG: shutting down30942026-10-01 10:14:13.493 UTC [133] LOG: checkpoint starting: shutdown immediate30952026-10-01 10:14:15.240 UTC [133] LOG: checkpoint complete: wrote 10840 buffers (66.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.280 s, sync=1.412 s, total=1.748 s; sync files=28648, longest=0.014 s, average=0.001 s; distance=396513 kB, estimate=396513 kB; lsn=0/19A9E298, redo lsn=0/19A9E29830962026-10-01 10:14:15.323 UTC [128] LOG: database system is shut down3097Running OIDC tests...3098=== RUN TestAudienceForIssuer3099=== PAUSE TestAudienceForIssuer3100=== RUN TestGlobMatch3101=== PAUSE TestGlobMatch3102=== RUN TestValidateToken_ValidToken3103=== PAUSE TestValidateToken_ValidToken3104=== RUN TestValidateToken_WrongAudience3105=== PAUSE TestValidateToken_WrongAudience3106=== RUN TestValidateToken_Expired3107=== PAUSE TestValidateToken_Expired3108=== RUN TestValidateToken_BoundClaimsMismatch3109=== PAUSE TestValidateToken_BoundClaimsMismatch3110=== RUN TestValidateToken_BoundSubjectMismatch3111=== PAUSE TestValidateToken_BoundSubjectMismatch3112=== RUN TestValidateToken_MultipleProviders3113=== PAUSE TestValidateToken_MultipleProviders3114=== RUN TestValidateToken_NoMatchingProvider3115=== PAUSE TestValidateToken_NoMatchingProvider3116=== RUN TestValidateToken_KubernetesServiceAccount3117=== PAUSE TestValidateToken_KubernetesServiceAccount3118=== RUN TestNewValidator_KubernetesRequiresCA3119=== PAUSE TestNewValidator_KubernetesRequiresCA3120=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3121=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3122=== RUN TestPins_ReservedForMatchingRule3123=== PAUSE TestPins_ReservedForMatchingRule3124=== RUN TestPins_TopLevelShorthand3125=== PAUSE TestPins_TopLevelShorthand3126=== RUN TestPins_ConfigValidation3127=== PAUSE TestPins_ConfigValidation3128=== RUN TestScopes_LegacyProviderDefaultsToWrite3129=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3130=== RUN TestScopes_Rules3131=== PAUSE TestScopes_Rules3132=== RUN TestScopes_ConfigValidation3133=== PAUSE TestScopes_ConfigValidation3134=== CONT TestAudienceForIssuer3135=== CONT TestValidateToken_KubernetesServiceAccount3136=== CONT TestScopes_Rules3137--- PASS: TestAudienceForIssuer (0.00s)3138=== CONT TestValidateToken_NoMatchingProvider3139=== CONT TestValidateToken_MultipleProviders3140=== CONT TestValidateToken_BoundSubjectMismatch3141=== CONT TestValidateToken_BoundClaimsMismatch3142=== CONT TestValidateToken_Expired3143=== CONT TestValidateToken_WrongAudience3144=== CONT TestValidateToken_ValidToken3145=== CONT TestGlobMatch3146=== RUN TestGlobMatch/foo_foo3147=== PAUSE TestGlobMatch/foo_foo3148=== CONT TestPins_ConfigValidation3149=== CONT TestPins_ReservedForMatchingRule3150=== CONT TestPins_TopLevelShorthand3151=== CONT TestScopes_LegacyProviderDefaultsToWrite3152=== CONT TestScopes_ConfigValidation3153=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3154=== CONT TestNewValidator_KubernetesRequiresCA3155=== RUN TestGlobMatch/foo_bar3156=== PAUSE TestGlobMatch/foo_bar3157=== RUN TestGlobMatch/*_3158=== PAUSE TestGlobMatch/*_3159=== RUN TestGlobMatch/*_anything3160=== PAUSE TestGlobMatch/*_anything3161=== RUN TestGlobMatch/foo*_foo3162=== PAUSE TestGlobMatch/foo*_foo3163=== RUN TestGlobMatch/foo*_foobar3164=== PAUSE TestGlobMatch/foo*_foobar3165=== RUN TestGlobMatch/foo*_bar3166=== PAUSE TestGlobMatch/foo*_bar3167=== RUN TestGlobMatch/*bar_bar3168=== PAUSE TestGlobMatch/*bar_bar3169=== RUN TestGlobMatch/*bar_foobar3170=== PAUSE TestGlobMatch/*bar_foobar3171=== RUN TestGlobMatch/*bar_foo3172=== PAUSE TestGlobMatch/*bar_foo3173=== RUN TestGlobMatch/foo*bar_foobar3174=== PAUSE TestGlobMatch/foo*bar_foobar3175=== RUN TestGlobMatch/foo*bar_foo123bar3176=== PAUSE TestGlobMatch/foo*bar_foo123bar3177=== RUN TestGlobMatch/foo*bar_foobarbaz3178=== PAUSE TestGlobMatch/foo*bar_foobarbaz3179=== RUN TestGlobMatch/*/*_foo/bar3180=== PAUSE TestGlobMatch/*/*_foo/bar3181=== RUN TestGlobMatch/*/*_foo3182=== PAUSE TestGlobMatch/*/*_foo3183=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3184=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3185=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03186=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03187=== RUN TestGlobMatch/refs/*/main_refs/heads/main3188=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3189=== RUN TestGlobMatch/fo?_foo3190=== PAUSE TestGlobMatch/fo?_foo3191=== RUN TestGlobMatch/fo?_fo3192=== PAUSE TestGlobMatch/fo?_fo3193=== RUN TestGlobMatch/fo?_fooo3194=== PAUSE TestGlobMatch/fo?_fooo3195=== RUN TestGlobMatch/?oo_foo3196=== PAUSE TestGlobMatch/?oo_foo3197=== RUN TestGlobMatch/?oo_boo3198=== PAUSE TestGlobMatch/?oo_boo3199=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3200=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3201=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3202=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3203=== CONT TestGlobMatch/foo_foo3204=== CONT TestGlobMatch/*/*_foo3205=== CONT TestGlobMatch/*/*_foo/bar3206=== CONT TestGlobMatch/foo*bar_foobarbaz3207=== CONT TestGlobMatch/foo*bar_foo123bar3208=== CONT TestGlobMatch/fo?_fooo3209=== CONT TestGlobMatch/foo*_foobar3210=== CONT TestGlobMatch/foo*_foo3211=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3212=== CONT TestGlobMatch/foo*bar_foobar3213=== CONT TestGlobMatch/*_3214=== CONT TestGlobMatch/*bar_foo3215=== CONT TestGlobMatch/*bar_foobar3216=== CONT TestGlobMatch/*bar_bar3217=== CONT TestGlobMatch/foo*_bar3218=== CONT TestGlobMatch/fo?_fo3219=== CONT TestGlobMatch/*_anything3220=== CONT TestGlobMatch/foo_bar3221=== CONT TestGlobMatch/fo?_foo3222=== CONT TestGlobMatch/refs/*/main_refs/heads/main3223=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3224=== CONT TestGlobMatch/?oo_boo3225=== CONT TestGlobMatch/?oo_foo3226=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03227=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3228--- PASS: TestGlobMatch (0.00s)3229 --- PASS: TestGlobMatch/foo_foo (0.00s)3230 --- PASS: TestGlobMatch/*/*_foo (0.00s)3231 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3232 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3233 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3234 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3235 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3236 --- PASS: TestGlobMatch/foo*_foo (0.00s)3237 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3238 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3239 --- PASS: TestGlobMatch/*_ (0.00s)3240 --- PASS: TestGlobMatch/foo_bar (0.00s)3241 --- PASS: TestGlobMatch/fo?_foo (0.00s)3242 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3243 --- PASS: TestGlobMatch/*bar_foo (0.00s)3244 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3245 --- PASS: TestGlobMatch/?oo_boo (0.00s)3246 --- PASS: TestGlobMatch/?oo_foo (0.00s)3247 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3248 --- PASS: TestGlobMatch/*bar_bar (0.00s)3249 --- PASS: TestGlobMatch/foo*_bar (0.00s)3250 --- PASS: TestGlobMatch/fo?_fo (0.00s)3251 --- PASS: TestGlobMatch/*_anything (0.00s)3252 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3253 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3254--- PASS: TestScopes_ConfigValidation (0.01s)3255--- PASS: TestPins_ConfigValidation (0.01s)32562026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45045/oidc32572026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42199/oidc32582026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42023/oidc3259--- PASS: TestValidateToken_ValidToken (0.02s)3260--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)3261--- PASS: TestScopes_Rules (0.03s)32622026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46483/oidc3263--- PASS: TestValidateToken_Expired (0.05s)32642026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46323/oidc3265--- PASS: TestValidateToken_WrongAudience (0.05s)32662026/10/01 10:14:17 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233267--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)32682026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37371/oidc32692026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42409/oidc3270--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)3271--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)32722026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44757/oidc3273--- PASS: TestPins_TopLevelShorthand (0.07s)32742026/10/01 10:14:17 http: TLS handshake error from 127.0.0.1:47436: remote error: tls: bad certificate3275--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)32762026/10/01 10:14:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39755/oidc32772026/10/01 10:14:17 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45333/oidc3278--- PASS: TestValidateToken_MultipleProviders (0.09s)32792026/10/01 10:14:17 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:454013280--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)32812026/10/01 10:14:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38805/oidc3282--- PASS: TestPins_ReservedForMatchingRule (0.10s)32832026/10/01 10:14:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41387/oidc3284--- PASS: TestValidateToken_NoMatchingProvider (0.13s)3285PASS3286Running hook tests...3287=== RUN TestSendPathsEmpty3288=== PAUSE TestSendPathsEmpty3289=== RUN TestQueueEnqueueAndFetch3290=== PAUSE TestQueueEnqueueAndFetch3291=== RUN TestQueueDeduplication3292=== PAUSE TestQueueDeduplication3293=== RUN TestQueueRemove3294=== PAUSE TestQueueRemove3295=== RUN TestQueueFetchBatchLimit3296=== PAUSE TestQueueFetchBatchLimit3297=== RUN TestQueueRetryMovesToBack3298=== PAUSE TestQueueRetryMovesToBack3299=== RUN TestQueueFetchRemoveLifecycle3300=== PAUSE TestQueueFetchRemoveLifecycle3301=== RUN TestQueueConcurrentWriters3302=== PAUSE TestQueueConcurrentWriters3303=== RUN TestQueueRemoveLargeClosure3304=== PAUSE TestQueueRemoveLargeClosure3305=== RUN TestServerClientIntegration3306=== PAUSE TestServerClientIntegration3307=== RUN TestServerQueueError3308=== PAUSE TestServerQueueError3309=== RUN TestGetListenerSocketActivation3310 server_test.go:210: === RUN TestGetListenerSocketActivation3311 --- PASS: TestGetListenerSocketActivation (0.00s)3312 PASS3313 3314--- PASS: TestGetListenerSocketActivation (0.01s)3315=== RUN TestDrainIsolatesPoisonPath3316=== PAUSE TestDrainIsolatesPoisonPath3317=== RUN TestRunNotBlockedByPoisonHead3318=== PAUSE TestRunNotBlockedByPoisonHead3319=== RUN TestDrainGivesUpWhenServerDown3320=== PAUSE TestDrainGivesUpWhenServerDown3321=== RUN TestFailedPathPrunedByLaterClosure3322=== PAUSE TestFailedPathPrunedByLaterClosure3323=== RUN TestWorkerUploadsAndRemoves3324=== PAUSE TestWorkerUploadsAndRemoves3325=== RUN TestWorkerSkipsGCdPaths3326=== PAUSE TestWorkerSkipsGCdPaths3327=== RUN TestWorkerPrunesClosureDeps3328=== PAUSE TestWorkerPrunesClosureDeps3329=== RUN TestDrainTimeout3330=== PAUSE TestDrainTimeout3331=== CONT TestSendPathsEmpty3332=== CONT TestServerQueueError3333--- PASS: TestSendPathsEmpty (0.00s)3334=== CONT TestQueueFetchBatchLimit3335=== CONT TestQueueRemove3336=== CONT TestQueueDeduplication3337=== CONT TestQueueRetryMovesToBack3338=== CONT TestQueueEnqueueAndFetch3339=== CONT TestServerClientIntegration33402026/10/01 10:14:17 ERROR Failed to queue paths error="permission denied" count=13341=== CONT TestQueueConcurrentWriters3342=== CONT TestQueueFetchRemoveLifecycle3343=== CONT TestQueueRemoveLargeClosure3344=== CONT TestWorkerPrunesClosureDeps3345--- PASS: TestServerQueueError (0.00s)3346=== CONT TestWorkerUploadsAndRemoves3347=== CONT TestDrainTimeout3348=== CONT TestDrainGivesUpWhenServerDown3349=== CONT TestWorkerSkipsGCdPaths3350=== CONT TestFailedPathPrunedByLaterClosure3351--- PASS: TestServerClientIntegration (0.00s)3352=== CONT TestRunNotBlockedByPoisonHead3353=== CONT TestDrainIsolatesPoisonPath33542026/10/01 10:14:17 INFO Upload queue status pending=333552026/10/01 10:14:17 INFO Uploading batch count=133562026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=133572026/10/01 10:14:17 INFO Uploading batch count=133582026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=133592026/10/01 10:14:17 INFO Uploading batch count=433602026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=43361--- PASS: TestQueueFetchBatchLimit (0.02s)33622026/10/01 10:14:17 INFO Uploading batch count=233632026/10/01 10:14:17 INFO Uploading batch count=233642026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=233652026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3915398590/002/a3366--- PASS: TestQueueEnqueueAndFetch (0.02s)33672026/10/01 10:14:17 INFO Upload queue status pending=233682026/10/01 10:14:17 INFO Upload queue status pending=233692026/10/01 10:14:17 INFO Upload queue status pending=233702026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2246871160/002/bbb3371--- PASS: TestQueueRetryMovesToBack (0.02s)33722026/10/01 10:14:17 INFO Uploading batch count=13373--- PASS: TestQueueFetchRemoveLifecycle (0.02s)33742026/10/01 10:14:17 INFO Uploading batch count=133752026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3915398590/002/b3376--- PASS: TestQueueDeduplication (0.02s)33772026/10/01 10:14:17 INFO Uploading batch count=233782026/10/01 10:14:17 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3655776516/002/nonexistent33792026/10/01 10:14:17 INFO Uploading batch count=233802026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=233812026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3915398590/002/c33822026/10/01 10:14:17 INFO Uploading batch count=133832026/10/01 10:14:17 INFO Uploading batch count=13384--- PASS: TestQueueRemove (0.02s)33852026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3915398590/002/d33862026/10/01 10:14:17 INFO Uploading batch count=133872026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=133882026/10/01 10:14:17 INFO Uploading batch count=233892026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=233902026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3915398590/002/e33912026/10/01 10:14:17 INFO Uploading batch count=13392--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)33932026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=133942026/10/01 10:14:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3915398590/002/f33952026/10/01 10:14:17 INFO Uploading batch count=133962026/10/01 10:14:17 ERROR Upload failed error="upload failed" count=133972026/10/01 10:14:17 ERROR Drain finished with paths left in queue remaining=1033982026/10/01 10:14:17 ERROR Drain finished with paths left in queue remaining=13399--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3400--- PASS: TestDrainIsolatesPoisonPath (0.02s)3401--- PASS: TestWorkerSkipsGCdPaths (0.03s)3402--- PASS: TestWorkerPrunesClosureDeps (0.04s)3403--- PASS: TestWorkerUploadsAndRemoves (0.04s)3404--- PASS: TestQueueRemoveLargeClosure (0.07s)34052026/10/01 10:14:17 ERROR Upload failed error="context deadline exceeded" count=234062026/10/01 10:14:17 ERROR Drain finished with paths left in queue remaining=43407--- PASS: TestDrainTimeout (0.22s)3408--- PASS: TestQueueConcurrentWriters (0.38s)34092026/10/01 10:14:18 INFO Uploading batch count=134102026/10/01 10:14:18 INFO Uploading batch count=134112026/10/01 10:14:18 INFO Uploading batch count=134122026/10/01 10:14:18 ERROR Upload failed error="upload failed" count=134132026/10/01 10:14:18 INFO Uploading batch count=134142026/10/01 10:14:18 ERROR Upload failed error="upload failed" count=134152026/10/01 10:14:18 INFO Uploading batch count=134162026/10/01 10:14:18 ERROR Upload failed error="upload failed" count=134172026/10/01 10:14:18 INFO Uploading batch count=134182026/10/01 10:14:18 ERROR Upload failed error="upload failed" count=134192026/10/01 10:14:18 ERROR Drain finished with paths left in queue remaining=13420--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3421PASS