niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #310
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestScriptTokenNoExpiryRerunsEveryCall96=== CONT TestStreamPushReportsSignatures97=== CONT TestStreamPushRequestLine98=== CONT TestFileTokenEmpty99=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess100=== CONT TestStreamPushIsolatesFailures101=== CONT TestStreamPushBatchesUnderLoad102=== CONT TestEncodeNixBase32103=== RUN TestEncodeNixBase32/test_string_hash104=== PAUSE TestEncodeNixBase32/test_string_hash1052026/10/01 09:33:49 ERROR Upload failed error="bad path" count=3106=== RUN TestEncodeNixBase32/empty_input107=== PAUSE TestEncodeNixBase32/empty_input108=== CONT TestStreamPushReportsEveryPath1092026/10/01 09:33:49 WARN Rate limiter enabled after throttle name=server-test rate=5110=== CONT TestStreamPushGivesUpOnDeadServer1112026/10/01 09:33:49 ERROR Upload failed error=boom count=1112--- PASS: TestStreamPushReportsEveryPath (0.00s)113=== CONT TestShellSplitErrors1142026/10/01 09:33:49 ERROR Upload failed error="connection refused" count=201152026/10/01 09:33:49 ERROR Server seems unavailable, giving up on batch untried=171162026/10/01 09:33:49 ERROR Upload failed error=boom count=1117--- PASS: TestShellSplitErrors (0.00s)118=== CONT TestShellSplit119=== CONT TestDoWithRetry_BodyReplayedViaGetBody120--- PASS: TestShellSplit (0.00s)121--- PASS: TestFileTokenEmpty (0.00s)122--- PASS: TestStreamPushIsolatesFailures (0.00s)123--- PASS: TestStreamPushReportsSignatures (0.00s)124=== CONT TestResolveStorePath125=== CONT TestRateLimiterFeedback126=== RUN TestRateLimiterFeedback/429_enables_limiter127--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)128=== PAUSE TestRateLimiterFeedback/429_enables_limiter129=== RUN TestRateLimiterFeedback/503_enables_limiter130=== CONT TestParsePathInfoJSONMultiplePaths131=== CONT TestPathInfoCACompatibility132=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths133=== RUN TestPathInfoCACompatibility/null_ca_field134=== PAUSE TestRateLimiterFeedback/503_enables_limiter135=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter136=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter137=== PAUSE TestPathInfoCACompatibility/null_ca_field138=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter139=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter140=== RUN TestPathInfoCACompatibility/old_string_format_-_text141=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text142=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive143=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive144=== CONT TestParsePathInfoJSON145=== RUN TestPathInfoCACompatibility/new_structured_format_-_text146=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text147=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== RUN TestParsePathInfoJSON/Nix_format150=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method151=== PAUSE TestParsePathInfoJSON/Nix_format152=== RUN TestParsePathInfoJSON/Lix_format153=== PAUSE TestParsePathInfoJSON/Lix_format154=== RUN TestParsePathInfoJSON/empty_input155=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157=== CONT TestGetStorePathHash158=== RUN TestGetStorePathHash/valid_store_path159--- PASS: TestResolveStorePath (0.00s)160=== CONT TestPathInfoHashCompatibility161=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon165=== PAUSE TestGetStorePathHash/valid_store_path166=== RUN TestGetStorePathHash/basename_without_hyphen_should_error167=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error168=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error169=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error170=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error171--- PASS: TestDoServerRequestAttachesToken (0.00s)172=== CONT TestEncodeNixBase32WithRealHash173=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error174=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI175--- PASS: TestEncodeNixBase32WithRealHash (0.00s)176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI177=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512179=== CONT TestPartSizeForNAR180=== RUN TestPartSizeForNAR/zero_stays_at_minimum181=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum182=== CONT TestConvertHashToNix32183=== CONT TestDumpPathWriterError1842026/10/01 09:33:49 WARN Rate limiter enabled after throttle name=server-test rate=5185=== RUN TestPartSizeForNAR/small_stays_at_minimum186=== RUN TestConvertHashToNix32/SRI_format_to_Nix32187=== PAUSE TestPartSizeForNAR/small_stays_at_minimum188=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum189=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum1902026/10/01 09:33:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65277191=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32192=== RUN TestConvertHashToNix32/already_Nix32_format193=== PAUSE TestConvertHashToNix32/already_Nix32_format194=== PAUSE TestParsePathInfoJSON/empty_input195=== CONT TestDumpPathSingleFile196=== RUN TestParsePathInfoJSON/whitespace_only197=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts198=== PAUSE TestParsePathInfoJSON/whitespace_only199=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts200=== RUN TestConvertHashToNix32/invalid_format201=== RUN TestPartSizeForNAR/1_TiB202=== PAUSE TestConvertHashToNix32/invalid_format203=== RUN TestParsePathInfoJSON/invalid_JSON204=== PAUSE TestPartSizeForNAR/1_TiB205=== RUN TestPartSizeForNAR/5_TiB_S3_max_object206=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object207=== RUN TestPartSizeForNAR/capped_at_5_GiB208=== PAUSE TestPartSizeForNAR/capped_at_5_GiB209=== CONT TestUploadMultipart_SupersededByPeer210=== RUN TestUploadMultipart_SupersededByPeer/exists211=== PAUSE TestUploadMultipart_SupersededByPeer/exists212=== PAUSE TestParsePathInfoJSON/invalid_JSON213=== CONT TestDumpPathMatchesNix214=== RUN TestUploadMultipart_SupersededByPeer/missing215=== PAUSE TestUploadMultipart_SupersededByPeer/missing216=== CONT TestScriptTokenBadJSON2172026/10/01 09:33:49 WARN Rate limiter backed off name=server-test rate=52182026/10/01 09:33:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65277219=== CONT TestScriptTokenEmptyCommand220--- PASS: TestScriptTokenEmptyCommand (0.00s)221=== CONT TestScriptTokenScriptFails222--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)223=== CONT TestSetClientTLSDoesNotMutateDefaultTransport224--- PASS: TestScriptTokenScriptFails (0.00s)225=== CONT TestFileTokenMissing226--- PASS: TestFileTokenMissing (0.00s)227=== CONT TestFileTokenReadsAndCaches228--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)229=== CONT TestStaticToken230--- PASS: TestStaticToken (0.00s)231=== CONT TestSetClientTLSErrors232--- PASS: TestFileTokenReadsAndCaches (0.00s)233=== CONT TestScriptTokenEmptyToken234=== RUN TestSetClientTLSErrors/missing_cert_file235=== PAUSE TestSetClientTLSErrors/missing_cert_file236=== RUN TestSetClientTLSErrors/missing_key_file237=== PAUSE TestSetClientTLSErrors/missing_key_file238=== RUN TestSetClientTLSErrors/missing_ca_file239=== PAUSE TestSetClientTLSErrors/missing_ca_file240=== RUN TestSetClientTLSErrors/invalid_ca_file241=== PAUSE TestSetClientTLSErrors/invalid_ca_file242=== CONT TestClientSignaturesByStorePath243--- PASS: TestClientSignaturesByStorePath (0.00s)244=== CONT TestSetClientTLS245=== RUN TestSetClientTLS/rejects_connection_without_client_cert246=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert247=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA248=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA249=== RUN TestSetClientTLS/preserves_debug_logging_transport250=== PAUSE TestSetClientTLS/preserves_debug_logging_transport251=== CONT TestScriptTokenCachesUntilRefresh252--- PASS: TestScriptTokenBadJSON (0.01s)253=== CONT TestFilterOversizedClosures254=== RUN TestFilterOversizedClosures/no_limit_keeps_everything255=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything256=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped257=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped258=== RUN TestFilterOversizedClosures/all_closures_skipped259=== PAUSE TestFilterOversizedClosures/all_closures_skipped260=== CONT TestUploadMultipart_PartsInParallel261--- PASS: TestStreamPushRequestLine (0.02s)262=== CONT TestRegisterUploadedObjectReusesConnections263--- PASS: TestScriptTokenEmptyToken (0.02s)264=== CONT TestEncodeNixBase32/test_string_hash265=== CONT TestEncodeNixBase32/empty_input266--- PASS: TestEncodeNixBase32 (0.00s)267 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)268 --- PASS: TestEncodeNixBase32/empty_input (0.00s)269=== CONT TestCaseHackSuffix270--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)271=== CONT TestRateLimiterFeedback/429_enables_limiter2722026/10/01 09:33:49 WARN Rate limiter enabled after throttle name=server-test rate=52732026/10/01 09:33:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:653472742026/10/01 09:33:49 WARN Rate limiter backed off name=server-test rate=5275=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter276=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter277=== CONT TestRateLimiterFeedback/503_enables_limiter2782026/10/01 09:33:49 WARN Rate limiter enabled after throttle name=server-test rate=52792026/10/01 09:33:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:653552802026/10/01 09:33:49 WARN Rate limiter backed off name=server-test rate=5281--- PASS: TestRateLimiterFeedback (0.00s)282 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)283 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)284 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)285 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)286=== CONT TestPathInfoCACompatibility/null_ca_field287=== CONT TestPathInfoCACompatibility/new_structured_format_-_text288=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method289=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive290=== CONT TestPathInfoCACompatibility/old_string_format_-_text291--- PASS: TestPathInfoCACompatibility (0.00s)292 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)293 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)294 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)295 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)296 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)297=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths298=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths299--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)301 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)302=== CONT TestGetStorePathHash/valid_store_path303=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error304=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error305=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)306=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512307=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI308=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon309--- PASS: TestPathInfoHashCompatibility (0.00s)310 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)311 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)312 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)313 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)314=== CONT TestGetStorePathHash/basename_without_hyphen_should_error315--- PASS: TestGetStorePathHash (0.00s)316 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)317 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)318 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)319 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)320=== CONT TestConvertHashToNix32/SRI_format_to_Nix32321=== CONT TestConvertHashToNix32/already_Nix32_format322=== CONT TestConvertHashToNix32/invalid_format323--- PASS: TestConvertHashToNix32 (0.00s)324 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)325 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)326 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)327=== CONT TestPartSizeForNAR/zero_stays_at_minimum328=== CONT TestPartSizeForNAR/capped_at_5_GiB329=== CONT TestPartSizeForNAR/5_TiB_S3_max_object330=== CONT TestPartSizeForNAR/1_TiB331=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts332=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum333=== CONT TestPartSizeForNAR/small_stays_at_minimum334--- PASS: TestPartSizeForNAR (0.00s)335 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)336 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)337 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)338 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)339 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)340 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)341 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)342=== CONT TestParsePathInfoJSON/Nix_format343=== CONT TestUploadMultipart_SupersededByPeer/exists344=== CONT TestParsePathInfoJSON/empty_input345=== CONT TestParsePathInfoJSON/invalid_JSON346=== CONT TestParsePathInfoJSON/whitespace_only347=== CONT TestParsePathInfoJSON/Lix_format348--- PASS: TestParsePathInfoJSON (0.00s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)351 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)352 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)353 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)354=== CONT TestUploadMultipart_SupersededByPeer/missing355--- PASS: TestDumpPathWriterError (0.04s)356=== CONT TestSetClientTLSErrors/missing_cert_file357=== CONT TestSetClientTLSErrors/missing_ca_file358=== CONT TestSetClientTLSErrors/invalid_ca_file359=== CONT TestSetClientTLSErrors/missing_key_file360--- PASS: TestSetClientTLSErrors (0.00s)361 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)362 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)363 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)365=== CONT TestSetClientTLS/rejects_connection_without_client_cert366--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)367 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)368 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)369=== CONT TestSetClientTLS/preserves_debug_logging_transport370=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA371--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)372=== CONT TestFilterOversizedClosures/no_limit_keeps_everything373=== CONT TestFilterOversizedClosures/all_closures_skipped3742026/10/01 09:33:49 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=50375=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3762026/10/01 09:33:49 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=2000377--- PASS: TestFilterOversizedClosures (0.00s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)381--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)3822026/10/01 09:33:49 http: TLS handshake error from 127.0.0.1:65362: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.06s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.63s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-41057-1805751233/postgres3078648817/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-41057-1805751233/postgres3078648817/data -l logfile start421422/nix/var/nix/builds/nix-41057-1805751233/postgres3078648817:5432 - no response4232026-10-01 09:33:50.897 UTC [41112] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 09:33:50.897 UTC [41112] LOG: listening on Unix socket "/nix/var/nix/builds/nix-41057-1805751233/postgres3078648817/.s.PGSQL.5432"4252026-10-01 09:33:50.899 UTC [41119] LOG: database system was shut down at 2026-10-01 09:33:50 UTC4262026-10-01 09:33:50.900 UTC [41112] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-41057-1805751233/postgres3078648817:5432 - accepting connections428{"timestamp":"2026-10-01T09:33:51.114432Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2e55d397-744a-4f2d-8451-5c40ea3cdfca","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(9)"}429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestLeadElectsOneAndHandsOver470=== PAUSE TestLeadElectsOneAndHandsOver471=== RUN TestLeadIncumbentWinsAfterRestart4722026-10-01 09:33:51.393 UTC [41149] ERROR: relation "goose_db_version" does not exist at character 364732026-10-01 09:33:51.393 UTC [41149] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/10/01 09:33:51 OK 20241026095416_initial_model.sql (4.16ms)4752026/10/01 09:33:51 OK 20251210153512_drop_unused_gin_index.sql (542.54µs)4762026/10/01 09:33:51 OK 20251218171726_add_pins.sql (941.63µs)4772026/10/01 09:33:51 OK 20260628120000_add_object_size_and_stats.sql (920.67µs)4782026/10/01 09:33:51 OK 20260905000000_add_claims.sql (1.19ms)4792026/10/01 09:33:51 OK 20260920000000_drop_claims.sql (644.88µs)4802026/10/01 09:33:51 OK 20260923120000_add_pushes.sql (421.29µs)4812026/10/01 09:33:51 goose: successfully migrated database to version: 202609231200004822026/10/01 09:33:51 OK 1_commit_pending_closure.sql (971.67µs)4832026/10/01 09:33:51 OK 2_object_stats_trigger.sql (228.25µs)4842026/10/01 09:33:51 OK 3_commit_push.sql (203.71µs)4852026/10/01 09:33:51 goose: up to current file version: 34862026/10/01 09:33:51 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 09:33:52 INFO lead: released remote=192.0.2.1:12344882026/10/01 09:33:52 INFO lead: acquired remote=192.0.2.1:12344892026/10/01 09:33:52 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (0.90s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestGCAdvisoryLockBlocksConcurrentRun4942026-10-01 09:33:52.206 UTC [41153] ERROR: relation "goose_db_version" does not exist at character 364952026-10-01 09:33:52.206 UTC [41153] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4962026/10/01 09:33:52 OK 20241026095416_initial_model.sql (3.59ms)4972026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (370.54µs)4982026/10/01 09:33:52 OK 20251218171726_add_pins.sql (778.33µs)4992026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (852.96µs)5002026/10/01 09:33:52 OK 20260905000000_add_claims.sql (1.05ms)5012026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (605.38µs)5022026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (420.54µs)5032026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200005042026/10/01 09:33:52 OK 1_commit_pending_closure.sql (863.83µs)5052026/10/01 09:33:52 OK 2_object_stats_trigger.sql (189.25µs)5062026/10/01 09:33:52 OK 3_commit_push.sql (167.38µs)5072026/10/01 09:33:52 goose: up to current file version: 3508--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 09:33:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"663--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)664=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle665=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== RUN TestProxyWriteTimeout667=== PAUSE TestProxyWriteTimeout668=== RUN TestIsValidUploadKey669=== PAUSE TestIsValidUploadKey670=== RUN TestUploadHandlersRejectInvalidKeys671=== PAUSE TestUploadHandlersRejectInvalidKeys672=== RUN TestUploadHandlersRejectOversizedBody673=== PAUSE TestUploadHandlersRejectOversizedBody674=== RUN TestService_cleanupPendingClosuresHandler675=== PAUSE TestService_cleanupPendingClosuresHandler676=== RUN TestService_createPendingClosureHandler677=== PAUSE TestService_createPendingClosureHandler678=== RUN TestService_verifyS3Integrity679=== PAUSE TestService_verifyS3Integrity680=== RUN TestCompleteMultipartUnregistered681=== PAUSE TestCompleteMultipartUnregistered682=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT683=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT684=== CONT TestReadProxyNarStreaming685=== CONT TestIsValidCachePath686=== RUN TestIsValidCachePath/narinfo687=== CONT TestCompleteMultipartUpload_ErrorButObjectExists688=== PAUSE TestIsValidCachePath/narinfo689=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT690=== CONT TestProxyHeadersOnlyTrustedOnSocket691=== CONT TestSweepSkipsRowsLockedByPush692=== CONT TestIsValidUploadKey693=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars694=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars695=== CONT TestReadProxyNarinfoAlreadyDecompressed696=== CONT TestReadProxyNarinfo697=== RUN TestIsValidUploadKey/narinfo698=== PAUSE TestIsValidUploadKey/narinfo699=== RUN TestIsValidCachePath/nar_zst700=== RUN TestIsValidUploadKey/nar_zst701=== PAUSE TestIsValidUploadKey/nar_zst702=== PAUSE TestIsValidCachePath/nar_zst703=== RUN TestIsValidUploadKey/nar_xz704=== PAUSE TestIsValidUploadKey/nar_xz705=== RUN TestIsValidUploadKey/nar_plain706=== PAUSE TestIsValidUploadKey/nar_plain707=== RUN TestIsValidUploadKey/listing708=== RUN TestIsValidCachePath/nar_xz709=== PAUSE TestIsValidCachePath/nar_xz710=== PAUSE TestIsValidUploadKey/listing711=== RUN TestIsValidUploadKey/build_log712=== PAUSE TestIsValidUploadKey/build_log713=== RUN TestIsValidUploadKey/build_log_home-manager_file714=== PAUSE TestIsValidUploadKey/build_log_home-manager_file715=== RUN TestIsValidUploadKey/build_log_plus_in_name716=== CONT TestService_AuthMiddleware717=== RUN TestIsValidCachePath/nar_bz2718=== PAUSE TestIsValidCachePath/nar_bz2719=== RUN TestIsValidCachePath/nar_uncompressed720=== PAUSE TestIsValidCachePath/nar_uncompressed721=== RUN TestIsValidCachePath/ls722=== PAUSE TestIsValidUploadKey/build_log_plus_in_name723=== PAUSE TestIsValidCachePath/ls724=== RUN TestIsValidUploadKey/build_log_question_mark725=== RUN TestIsValidCachePath/log726=== PAUSE TestIsValidUploadKey/build_log_question_mark727=== PAUSE TestIsValidCachePath/log728=== RUN TestIsValidCachePath/realisation729=== RUN TestIsValidUploadKey/build_log_equals730=== PAUSE TestIsValidCachePath/realisation731=== PAUSE TestIsValidUploadKey/build_log_equals732=== RUN TestIsValidCachePath/nix-cache-info733=== PAUSE TestIsValidCachePath/nix-cache-info734=== RUN TestIsValidUploadKey/realisation735=== RUN TestIsValidCachePath/index.html736=== PAUSE TestIsValidUploadKey/realisation737=== PAUSE TestIsValidCachePath/index.html738=== RUN TestIsValidUploadKey/realisation_plus_in_output739=== RUN TestIsValidCachePath/traversal_parent740=== PAUSE TestIsValidUploadKey/realisation_plus_in_output741=== RUN TestIsValidUploadKey/nix-cache-info742=== PAUSE TestIsValidUploadKey/nix-cache-info743=== PAUSE TestIsValidCachePath/traversal_parent744=== RUN TestIsValidCachePath/traversal_in_middle745=== RUN TestIsValidUploadKey/index.html746=== PAUSE TestIsValidUploadKey/index.html747=== RUN TestIsValidUploadKey/narinfo_key,_nar_type748=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type749=== PAUSE TestIsValidCachePath/traversal_in_middle750=== RUN TestIsValidUploadKey/nar_key,_narinfo_type751=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type752=== RUN TestIsValidUploadKey/listing_key,_narinfo_type753=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type754=== RUN TestIsValidUploadKey/traversal755=== PAUSE TestIsValidUploadKey/traversal756=== RUN TestIsValidUploadKey/traversal_nar757=== PAUSE TestIsValidUploadKey/traversal_nar758=== RUN TestIsValidCachePath/invalid_char_e759=== RUN TestIsValidUploadKey/absolute760=== PAUSE TestIsValidUploadKey/absolute761=== PAUSE TestIsValidCachePath/invalid_char_e762=== RUN TestIsValidUploadKey/empty_key763=== PAUSE TestIsValidUploadKey/empty_key764=== RUN TestIsValidCachePath/invalid_char_u765=== RUN TestIsValidUploadKey/unknown_type766=== PAUSE TestIsValidCachePath/invalid_char_u767=== PAUSE TestIsValidUploadKey/unknown_type768=== RUN TestIsValidCachePath/random_path769=== CONT TestParseSize770--- PASS: TestParseSize (0.00s)771=== PAUSE TestIsValidCachePath/random_path772=== CONT TestProxyWriteTimeout773=== RUN TestIsValidCachePath/empty774=== RUN TestProxyWriteTimeout/narinfo775=== PAUSE TestIsValidCachePath/empty776=== RUN TestIsValidCachePath/leading_slash777=== PAUSE TestIsValidCachePath/leading_slash778=== RUN TestIsValidCachePath/wrong_extension779=== PAUSE TestProxyWriteTimeout/narinfo780=== RUN TestProxyWriteTimeout/1_GiB_nar781=== PAUSE TestIsValidCachePath/wrong_extension782=== RUN TestIsValidCachePath/short_hash783=== PAUSE TestProxyWriteTimeout/1_GiB_nar784=== PAUSE TestIsValidCachePath/short_hash785=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle786=== RUN TestProxyWriteTimeout/10_GiB_nar787=== PAUSE TestProxyWriteTimeout/10_GiB_nar788=== RUN TestProxyWriteTimeout/unknown_size789=== PAUSE TestProxyWriteTimeout/unknown_size790=== CONT TestSkippedUploadsHandler7912026/10/01 09:33:52 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000792--- PASS: TestSkippedUploadsHandler (0.01s)793=== CONT TestPresignedUploadRegisteredBeforeCommit7942026-10-01 09:33:52.826 UTC [41175] ERROR: relation "goose_db_version" does not exist at character 367952026-10-01 09:33:52.826 UTC [41175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026-10-01 09:33:52.826 UTC [41176] ERROR: relation "goose_db_version" does not exist at character 367972026-10-01 09:33:52.826 UTC [41176] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026-10-01 09:33:52.828 UTC [41177] ERROR: relation "goose_db_version" does not exist at character 367992026-10-01 09:33:52.828 UTC [41177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8002026-10-01 09:33:52.829 UTC [41178] ERROR: relation "goose_db_version" does not exist at character 368012026-10-01 09:33:52.829 UTC [41178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026-10-01 09:33:52.829 UTC [41179] ERROR: relation "goose_db_version" does not exist at character 368032026-10-01 09:33:52.829 UTC [41179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026-10-01 09:33:52.829 UTC [41180] ERROR: relation "goose_db_version" does not exist at character 368052026-10-01 09:33:52.829 UTC [41180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8062026-10-01 09:33:52.830 UTC [41181] ERROR: relation "goose_db_version" does not exist at character 368072026-10-01 09:33:52.830 UTC [41181] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026-10-01 09:33:52.830 UTC [41183] ERROR: relation "goose_db_version" does not exist at character 368092026-10-01 09:33:52.830 UTC [41183] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026-10-01 09:33:52.831 UTC [41182] ERROR: relation "goose_db_version" does not exist at character 368112026-10-01 09:33:52.831 UTC [41182] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026-10-01 09:33:52.832 UTC [41184] ERROR: relation "goose_db_version" does not exist at character 368132026-10-01 09:33:52.832 UTC [41184] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026/10/01 09:33:52 OK 20241026095416_initial_model.sql (8.08ms)8152026/10/01 09:33:52 OK 20241026095416_initial_model.sql (8.83ms)8162026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (947.21µs)8172026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)8182026/10/01 09:33:52 OK 20241026095416_initial_model.sql (8.5ms)8192026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)8202026/10/01 09:33:52 OK 20241026095416_initial_model.sql (9.64ms)8212026/10/01 09:33:52 OK 20251218171726_add_pins.sql (2.55ms)8222026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.82ms)8232026/10/01 09:33:52 OK 20241026095416_initial_model.sql (9.01ms)8242026/10/01 09:33:52 OK 20241026095416_initial_model.sql (10.39ms)8252026/10/01 09:33:52 OK 20241026095416_initial_model.sql (7.54ms)8262026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (534.21µs)8272026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (808.04µs)8282026/10/01 09:33:52 OK 20241026095416_initial_model.sql (8.42ms)8292026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (913.63µs)8302026/10/01 09:33:52 OK 20241026095416_initial_model.sql (8.6ms)8312026/10/01 09:33:52 OK 20241026095416_initial_model.sql (8.56ms)8322026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (756.08µs)8332026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.67ms)8342026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (1.59ms)8352026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (632.17µs)8362026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (690.92µs)8372026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (2.1ms)8382026/10/01 09:33:52 OK 20251210153512_drop_unused_gin_index.sql (836.5µs)8392026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.54ms)8402026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.68ms)8412026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.65ms)8422026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (1.59ms)8432026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.27ms)8442026/10/01 09:33:52 OK 20260905000000_add_claims.sql (2.28ms)8452026/10/01 09:33:52 OK 20251218171726_add_pins.sql (1.85ms)8462026/10/01 09:33:52 OK 20251218171726_add_pins.sql (2.58ms)8472026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)8482026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (1.24ms)8492026/10/01 09:33:52 OK 20260905000000_add_claims.sql (2.25ms)8502026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (2.13ms)8512026/10/01 09:33:52 OK 20251218171726_add_pins.sql (2.44ms)8522026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.22ms)8532026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (1.42ms)8542026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (2.39ms)8552026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.72ms)8562026/10/01 09:33:52 OK 20260905000000_add_claims.sql (2.99ms)8572026/10/01 09:33:52 OK 20260905000000_add_claims.sql (2.22ms)8582026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (2.33ms)8592026/10/01 09:33:52 OK 20260905000000_add_claims.sql (1.89ms)8602026/10/01 09:33:52 OK 20260628120000_add_object_size_and_stats.sql (1.99ms)8612026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (1.34ms)8622026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008632026/10/01 09:33:52 OK 20260905000000_add_claims.sql (2.37ms)8642026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (1.17ms)8652026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008662026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (934.42µs)8672026/10/01 09:33:52 OK 20260905000000_add_claims.sql (1.83ms)8682026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.46ms)8692026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.31ms)8702026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.72ms)8712026/10/01 09:33:52 OK 20260905000000_add_claims.sql (1.96ms)8722026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.66ms)8732026/10/01 09:33:52 OK 20260905000000_add_claims.sql (3ms)8742026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (1.21ms)8752026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008762026/10/01 09:33:52 OK 20260905000000_add_claims.sql (1.99ms)8772026/10/01 09:33:52 OK 2_object_stats_trigger.sql (559.17µs)8782026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.3ms)8792026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (1.47ms)8802026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008812026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (717.79µs)8822026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008832026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.8ms)8842026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (1.64ms)8852026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008862026/10/01 09:33:52 OK 3_commit_push.sql (581.88µs)8872026/10/01 09:33:52 goose: up to current file version: 38882026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.04ms)8892026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.02ms)8902026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.16ms)8912026/10/01 09:33:52 OK 2_object_stats_trigger.sql (697.21µs)8922026/10/01 09:33:52 OK 20260920000000_drop_claims.sql (1.66ms)8932026/10/01 09:33:52 OK 1_commit_pending_closure.sql (894.38µs)8942026/10/01 09:33:52 OK 2_object_stats_trigger.sql (551.67µs)8952026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (1.24ms)8962026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200008972026/10/01 09:33:52 OK 3_commit_push.sql (351.92µs)8982026/10/01 09:33:52 goose: up to current file version: 38992026/10/01 09:33:52 OK 3_commit_push.sql (450.88µs)9002026/10/01 09:33:52 goose: up to current file version: 39012026/10/01 09:33:52 OK 2_object_stats_trigger.sql (470.08µs)9022026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (672.83µs)9032026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200009042026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (588.25µs)9052026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200009062026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.37ms)9072026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.39ms)9082026/10/01 09:33:52 OK 3_commit_push.sql (260.38µs)9092026/10/01 09:33:52 goose: up to current file version: 39102026/10/01 09:33:52 OK 20260923120000_add_pushes.sql (790.25µs)9112026/10/01 09:33:52 goose: successfully migrated database to version: 202609231200009122026/10/01 09:33:52 OK 2_object_stats_trigger.sql (281.71µs)9132026/10/01 09:33:52 OK 3_commit_push.sql (190.71µs)9142026/10/01 09:33:52 goose: up to current file version: 39152026/10/01 09:33:52 OK 2_object_stats_trigger.sql (495.17µs)9162026/10/01 09:33:52 OK 1_commit_pending_closure.sql (859.75µs)9172026/10/01 09:33:52 OK 1_commit_pending_closure.sql (893.38µs)9182026/10/01 09:33:52 OK 3_commit_push.sql (311.71µs)9192026/10/01 09:33:52 goose: up to current file version: 39202026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.14ms)9212026/10/01 09:33:52 OK 2_object_stats_trigger.sql (201.83µs)9222026/10/01 09:33:52 OK 2_object_stats_trigger.sql (263.42µs)9232026/10/01 09:33:52 OK 3_commit_push.sql (168.42µs)9242026/10/01 09:33:52 goose: up to current file version: 39252026/10/01 09:33:52 OK 2_object_stats_trigger.sql (282.42µs)9262026/10/01 09:33:52 OK 1_commit_pending_closure.sql (1.12ms)9272026/10/01 09:33:52 OK 3_commit_push.sql (217.75µs)9282026/10/01 09:33:52 goose: up to current file version: 39292026/10/01 09:33:52 OK 3_commit_push.sql (132.17µs)9302026/10/01 09:33:52 goose: up to current file version: 39312026/10/01 09:33:52 OK 2_object_stats_trigger.sql (177.92µs)9322026/10/01 09:33:52 OK 3_commit_push.sql (175.29µs)9332026/10/01 09:33:52 goose: up to current file version: 39342026/10/01 09:33:52 INFO Starting HTTP server address=127.0.0.1:653869352026/10/01 09:33:52 INFO Starting HTTP server address=/nix/var/nix/builds/nix-41057-1805751233/TestProxyHeadersOnlyTrustedOnSocket2304009986/001/proxy.sock9362026/10/01 09:33:52 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9372026/10/01 09:33:52 INFO Shutdown signal received, draining in-flight requests timeout=10s938--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.43s)939=== CONT TestService_Rustfstest940--- PASS: TestReadProxyNarinfo (0.57s)941=== CONT TestClientPushesUseOnePush9422026/10/01 09:33:53 INFO Received uploads request method=POST path=/api/pending_closures943--- PASS: TestReadProxyNarStreaming (0.93s)944=== CONT TestFailedS3DeleteKeepsTombstone9452026/10/01 09:33:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9462026/10/01 09:33:53 INFO Received uploads request method=POST path=/api/pending_closures9472026/10/01 09:33:53 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9482026/10/01 09:33:53 INFO Received uploads request method=POST path=/api/pending_closures949--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.12s)950=== CONT TestForceGCDuringPushOffersSweptObject951=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows952=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows953=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check954=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check955=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9562026-10-01 09:33:53.736 UTC [41194] ERROR: relation "goose_db_version" does not exist at character 369572026-10-01 09:33:53.736 UTC [41194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC958--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.28s)959=== CONT TestGCSweepDeliversEachKeyOnce9602026/10/01 09:33:53 OK 20241026095416_initial_model.sql (93.93ms)9612026/10/01 09:33:53 OK 20251210153512_drop_unused_gin_index.sql (10.5ms)9622026/10/01 09:33:53 OK 20251218171726_add_pins.sql (16.19ms)9632026/10/01 09:33:53 OK 20260628120000_add_object_size_and_stats.sql (18.39ms)9642026-10-01 09:33:53.912 UTC [41197] ERROR: relation "goose_db_version" does not exist at character 369652026-10-01 09:33:53.912 UTC [41197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9662026/10/01 09:33:53 OK 20260905000000_add_claims.sql (27.62ms)9672026/10/01 09:33:53 OK 20260920000000_drop_claims.sql (13.5ms)9682026/10/01 09:33:53 OK 20260923120000_add_pushes.sql (8.1ms)9692026/10/01 09:33:53 goose: successfully migrated database to version: 202609231200009702026/10/01 09:33:53 OK 1_commit_pending_closure.sql (3.37ms)9712026/10/01 09:33:53 OK 2_object_stats_trigger.sql (646.17µs)9722026/10/01 09:33:53 OK 3_commit_push.sql (677.71µs)9732026/10/01 09:33:53 goose: up to current file version: 39742026/10/01 09:33:53 INFO Aborted multipart uploads count=09752026/10/01 09:33:53 WARN Force mode enabled - objects will be deleted immediately without grace period9762026/10/01 09:33:53 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=09772026/10/01 09:33:53 INFO Vacuumed table table=pending_closures9782026/10/01 09:33:53 INFO Vacuumed table table=pending_objects9792026/10/01 09:33:53 INFO Vacuumed table table=multipart_uploads9802026/10/01 09:33:53 INFO Vacuumed table table=closures9812026/10/01 09:33:54 INFO Vacuumed table table=objects9822026/10/01 09:33:54 INFO Aborted multipart uploads count=09832026/10/01 09:33:54 WARN Force mode enabled - objects will be deleted immediately without grace period9842026/10/01 09:33:54 OK 20241026095416_initial_model.sql (135.62ms)9852026/10/01 09:33:54 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=09862026/10/01 09:33:54 INFO Vacuumed table table=pending_closures9872026/10/01 09:33:54 INFO Vacuumed table table=pending_objects9882026/10/01 09:33:54 INFO Vacuumed table table=multipart_uploads9892026/10/01 09:33:54 INFO Vacuumed table table=closures9902026/10/01 09:33:54 INFO Vacuumed table table=objects9912026/10/01 09:33:54 OK 20251210153512_drop_unused_gin_index.sql (11.01ms)992--- PASS: TestSweepSkipsRowsLockedByPush (1.59s)993=== CONT TestTombstonedObjectOfferedWithoutWaiting9942026/10/01 09:33:54 OK 20251218171726_add_pins.sql (24.74ms)9952026/10/01 09:33:54 OK 20260628120000_add_object_size_and_stats.sql (18.97ms)9962026/10/01 09:33:54 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/01 09:33:54 OK 20260905000000_add_claims.sql (25.16ms)9982026/10/01 09:33:54 OK 20260920000000_drop_claims.sql (29.08ms)999--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.70s)1000=== CONT TestGCSweepSkipsPendingObjects10012026-10-01 09:33:54.199 UTC [41202] ERROR: relation "goose_db_version" does not exist at character 3610022026-10-01 09:33:54.199 UTC [41202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10032026/10/01 09:33:54 OK 20260923120000_add_pushes.sql (11.41ms)10042026/10/01 09:33:54 goose: successfully migrated database to version: 2026092312000010052026/10/01 09:33:54 OK 1_commit_pending_closure.sql (4.55ms)10062026/10/01 09:33:54 OK 2_object_stats_trigger.sql (924.88µs)10072026/10/01 09:33:54 OK 3_commit_push.sql (505.25µs)10082026/10/01 09:33:54 goose: up to current file version: 310092026/10/01 09:33:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1010--- PASS: TestService_AuthMiddleware (1.80s)1011=== CONT TestDeduplicatedObjectsRecordedAsPending10122026/10/01 09:33:54 OK 20241026095416_initial_model.sql (76.67ms)10132026/10/01 09:33:54 OK 20251210153512_drop_unused_gin_index.sql (9.81ms)10142026/10/01 09:33:54 OK 20251218171726_add_pins.sql (34.87ms)10152026/10/01 09:33:54 OK 20260628120000_add_object_size_and_stats.sql (10.42ms)10162026/10/01 09:33:54 OK 20260905000000_add_claims.sql (25.09ms)10172026-10-01 09:33:54.389 UTC [41207] ERROR: relation "goose_db_version" does not exist at character 3610182026-10-01 09:33:54.389 UTC [41207] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10192026/10/01 09:33:54 OK 20260920000000_drop_claims.sql (8.66ms)10202026/10/01 09:33:54 OK 20260923120000_add_pushes.sql (7.95ms)10212026/10/01 09:33:54 goose: successfully migrated database to version: 2026092312000010222026/10/01 09:33:54 OK 1_commit_pending_closure.sql (2.71ms)10232026/10/01 09:33:54 OK 2_object_stats_trigger.sql (547µs)10242026/10/01 09:33:54 OK 3_commit_push.sql (331.21µs)10252026/10/01 09:33:54 goose: up to current file version: 310262026/10/01 09:33:54 INFO Received uploads request method=POST path=/api/pending_closures10272026/10/01 09:33:54 OK 20241026095416_initial_model.sql (117.97ms)10282026/10/01 09:33:54 OK 20251210153512_drop_unused_gin_index.sql (8.58ms)10292026/10/01 09:33:54 OK 20251218171726_add_pins.sql (23.49ms)10302026/10/01 09:33:54 OK 20260628120000_add_object_size_and_stats.sql (55.76ms)10312026/10/01 09:33:54 OK 20260905000000_add_claims.sql (49.07ms)10322026/10/01 09:33:54 OK 20260920000000_drop_claims.sql (40.4ms)10332026/10/01 09:33:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1034--- PASS: TestService_Rustfstest (1.79s)1035=== CONT TestPushDedupSurvivesConcurrentGC10362026/10/01 09:33:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWJlNGYwYTYtZjc4My00ZTBiLTk2NTMtNjhiZWE3Zjk5MjBmLmY4ZjhjZGEzLTQwZGYtNGJmOC1iOGEwLWNhYTk4OTMxNjc4OXgxNzkwODQ3MjM0NDk0OTAzMDAw10372026/10/01 09:33:54 OK 20260923120000_add_pushes.sql (13.62ms)10382026/10/01 09:33:54 goose: successfully migrated database to version: 2026092312000010392026/10/01 09:33:54 OK 1_commit_pending_closure.sql (3.39ms)10402026/10/01 09:33:54 OK 2_object_stats_trigger.sql (703.13µs)10412026/10/01 09:33:54 OK 3_commit_push.sql (448.71µs)10422026/10/01 09:33:54 goose: up to current file version: 310432026/10/01 09:33:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWJlNGYwYTYtZjc4My00ZTBiLTk2NTMtNjhiZWE3Zjk5MjBmLmY4ZjhjZGEzLTQwZGYtNGJmOC1iOGEwLWNhYTk4OTMxNjc4OXgxNzkwODQ3MjM0NDk0OTAzMDAw parts=11044--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.24s)1045=== CONT TestGCMetrics10462026-10-01 09:33:54.791 UTC [41212] ERROR: relation "goose_db_version" does not exist at character 3610472026-10-01 09:33:54.791 UTC [41212] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10482026/10/01 09:33:54 OK 20241026095416_initial_model.sql (139.92ms)10492026/10/01 09:33:54 OK 20251210153512_drop_unused_gin_index.sql (10.21ms)10502026/10/01 09:33:54 OK 20251218171726_add_pins.sql (15.45ms)10512026/10/01 09:33:55 OK 20260628120000_add_object_size_and_stats.sql (19.52ms)10522026/10/01 09:33:55 OK 20260905000000_add_claims.sql (24.42ms)10532026/10/01 09:33:55 OK 20260920000000_drop_claims.sql (26.02ms)10542026/10/01 09:33:55 OK 20260923120000_add_pushes.sql (7.21ms)10552026/10/01 09:33:55 goose: successfully migrated database to version: 2026092312000010562026/10/01 09:33:55 OK 1_commit_pending_closure.sql (1.66ms)10572026/10/01 09:33:55 OK 2_object_stats_trigger.sql (336.08µs)10582026/10/01 09:33:55 OK 3_commit_push.sql (272.58µs)10592026/10/01 09:33:55 goose: up to current file version: 310602026/10/01 09:33:55 INFO Received uploads request method=POST path=/api/pending_closures10612026/10/01 09:33:55 INFO Aborted multipart uploads count=010622026/10/01 09:33:55 WARN Force mode enabled - objects will be deleted immediately without grace period10632026/10/01 09:33:55 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10642026/10/01 09:33:55 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1065--- PASS: TestFailedS3DeleteKeepsTombstone (1.78s)1066=== CONT TestGCBugBareHashReferences10672026-10-01 09:33:55.275 UTC [41223] ERROR: relation "goose_db_version" does not exist at character 3610682026-10-01 09:33:55.275 UTC [41223] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10692026/10/01 09:33:55 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/01 09:33:55 INFO Received push request method=POST path=/api/pushes10712026/10/01 09:33:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10722026/10/01 09:33:55 INFO Uploading hdxjf0mmmfch103v6j0kgscm79dgkh1a-shared-dep (136B)10732026/10/01 09:33:55 INFO Uploading ibaj62y0np0awyci3rjkvi9pjkrswryz-b (248B)10742026/10/01 09:33:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10752026/10/01 09:33:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10762026-10-01 09:33:55.333 UTC [41227] ERROR: relation "goose_db_version" does not exist at character 3610772026-10-01 09:33:55.333 UTC [41227] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10782026/10/01 09:33:55 WARN Failed to register uploaded object key=ibaj62y0np0awyci3rjkvi9pjkrswryz.ls error="server returned 404: 404 page not found\n"10792026/10/01 09:33:55 WARN Failed to register uploaded object key=dxq6r7wwhfhpafhqnhm8nqhzplkmi6a4.ls error="server returned 404: 404 page not found\n"10802026/10/01 09:33:55 WARN Failed to register uploaded object key=nar/0r83aksg8xi7qqwsnbxb6xfy6z7h65gkc944bkck3yrc3ri2f068.nar.zst error="server returned 404: 404 page not found\n"10812026/10/01 09:33:55 WARN Failed to register uploaded object key=hdxjf0mmmfch103v6j0kgscm79dgkh1a.ls error="server returned 404: 404 page not found\n"10822026/10/01 09:33:55 INFO Signed narinfos id=1 count=310832026/10/01 09:33:55 INFO Uploading 3 narinfos10842026/10/01 09:33:55 WARN Failed to register uploaded object key=dxq6r7wwhfhpafhqnhm8nqhzplkmi6a4.narinfo error="server returned 404: 404 page not found\n"10852026/10/01 09:33:55 WARN Failed to register uploaded object key=ibaj62y0np0awyci3rjkvi9pjkrswryz.narinfo error="server returned 404: 404 page not found\n"10862026/10/01 09:33:55 INFO Received complete push request method=POST path=/api/pushes/1/complete10872026/10/01 09:33:55 WARN Failed to register uploaded object key=hdxjf0mmmfch103v6j0kgscm79dgkh1a.narinfo error="server returned 404: 404 page not found\n"10882026/10/01 09:33:55 INFO Upload complete. (102ms)1089=== NAME TestClientPushesUseOnePush1090 client_pushes_test.go:97: Retrieved narinfo from S3:1091 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientPushesUseOnePush2424787315/001/store/hdxjf0mmmfch103v6j0kgscm79dgkh1a-shared-dep1092 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1093 Compression: zstd1094 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821095 NarSize: 1361096 References: 1097 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1098 client_pushes_test.go:97: Retrieved narinfo from S3:1099 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientPushesUseOnePush2424787315/001/store/dxq6r7wwhfhpafhqnhm8nqhzplkmi6a4-a1100 URL: nar/0r83aksg8xi7qqwsnbxb6xfy6z7h65gkc944bkck3yrc3ri2f068.nar.zst1101 Compression: zstd1102 NarHash: sha256:0r83aksg8xi7qqwsnbxb6xfy6z7h65gkc944bkck3yrc3ri2f0681103 NarSize: 2481104 References: /nix/var/nix/builds/nix-41057-1805751233/TestClientPushesUseOnePush2424787315/001/store/hdxjf0mmmfch103v6j0kgscm79dgkh1a-shared-dep1105 CA: text:sha256:0khymzp8fi54zbjra0m0k1ws7ri1v1qncyvg6d51m41rhpfppqhj1106 client_pushes_test.go:97: Retrieved narinfo from S3:1107 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientPushesUseOnePush2424787315/001/store/ibaj62y0np0awyci3rjkvi9pjkrswryz-b1108 URL: nar/0r83aksg8xi7qqwsnbxb6xfy6z7h65gkc944bkck3yrc3ri2f068.nar.zst1109 Compression: zstd1110 NarHash: sha256:0r83aksg8xi7qqwsnbxb6xfy6z7h65gkc944bkck3yrc3ri2f0681111 NarSize: 2481112 References: /nix/var/nix/builds/nix-41057-1805751233/TestClientPushesUseOnePush2424787315/001/store/hdxjf0mmmfch103v6j0kgscm79dgkh1a-shared-dep1113 CA: text:sha256:0khymzp8fi54zbjra0m0k1ws7ri1v1qncyvg6d51m41rhpfppqhj1114--- PASS: TestClientPushesUseOnePush (2.32s)1115=== CONT TestLeadEndsOnShutdown11162026-10-01 09:33:55.430 UTC [41229] ERROR: relation "goose_db_version" does not exist at character 3611172026-10-01 09:33:55.430 UTC [41229] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11182026/10/01 09:33:55 OK 20241026095416_initial_model.sql (118.2ms)11192026/10/01 09:33:55 OK 20251210153512_drop_unused_gin_index.sql (5.49ms)11202026/10/01 09:33:55 OK 20251218171726_add_pins.sql (14.99ms)11212026/10/01 09:33:55 OK 20241026095416_initial_model.sql (96.54ms)11222026/10/01 09:33:55 OK 20260628120000_add_object_size_and_stats.sql (16.13ms)11232026/10/01 09:33:55 OK 20251210153512_drop_unused_gin_index.sql (7.23ms)11242026/10/01 09:33:55 OK 20251218171726_add_pins.sql (19.04ms)11252026/10/01 09:33:55 OK 20260905000000_add_claims.sql (22.74ms)11262026/10/01 09:33:55 OK 20260628120000_add_object_size_and_stats.sql (16.04ms)11272026/10/01 09:33:55 OK 20260920000000_drop_claims.sql (13.04ms)1128--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.88s)1129=== CONT TestLeadElectsOneAndHandsOver11302026/10/01 09:33:55 INFO Aborted multipart uploads count=011312026/10/01 09:33:55 OK 20260923120000_add_pushes.sql (5.86ms)11322026/10/01 09:33:55 goose: successfully migrated database to version: 2026092312000011332026/10/01 09:33:55 OK 1_commit_pending_closure.sql (1.26ms)11342026/10/01 09:33:55 OK 2_object_stats_trigger.sql (282.96µs)11352026/10/01 09:33:55 OK 3_commit_push.sql (236.33µs)11362026/10/01 09:33:55 goose: up to current file version: 311372026/10/01 09:33:55 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/10/01 09:33:55 OK 20241026095416_initial_model.sql (80.33ms)11392026/10/01 09:33:55 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)11402026/10/01 09:33:55 OK 20260905000000_add_claims.sql (25.67ms)11412026/10/01 09:33:55 OK 20251218171726_add_pins.sql (33.11ms)11422026/10/01 09:33:55 OK 20260920000000_drop_claims.sql (26.11ms)11432026/10/01 09:33:55 OK 20260923120000_add_pushes.sql (4.72ms)11442026/10/01 09:33:55 goose: successfully migrated database to version: 2026092312000011452026/10/01 09:33:55 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=011462026/10/01 09:33:55 OK 1_commit_pending_closure.sql (2.43ms)11472026/10/01 09:33:55 INFO Vacuumed table table=pending_closures11482026/10/01 09:33:55 OK 2_object_stats_trigger.sql (329.71µs)11492026/10/01 09:33:55 OK 3_commit_push.sql (244.83µs)11502026/10/01 09:33:55 goose: up to current file version: 311512026/10/01 09:33:55 OK 20260628120000_add_object_size_and_stats.sql (17.53ms)11522026/10/01 09:33:55 INFO Vacuumed table table=pending_objects11532026/10/01 09:33:55 INFO Vacuumed table table=multipart_uploads11542026/10/01 09:33:55 INFO Vacuumed table table=closures11552026/10/01 09:33:55 INFO Vacuumed table table=objects1156--- PASS: TestGCSweepDeliversEachKeyOnce (1.83s)1157=== CONT TestResolveDBConnectionString1158=== RUN TestResolveDBConnectionString/flag_wins1159=== PAUSE TestResolveDBConnectionString/flag_wins1160=== RUN TestResolveDBConnectionString/file_when_flag_empty1161=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1162=== RUN TestResolveDBConnectionString/missing_file_is_an_error1163=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1164=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1165=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1166=== RUN TestResolveDBConnectionString/nothing_configured1167=== PAUSE TestResolveDBConnectionString/nothing_configured1168=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11692026/10/01 09:33:55 OK 20260905000000_add_claims.sql (41.79ms)11702026/10/01 09:33:55 OK 20260920000000_drop_claims.sql (15.99ms)11712026/10/01 09:33:55 OK 20260923120000_add_pushes.sql (6.04ms)11722026/10/01 09:33:55 goose: successfully migrated database to version: 2026092312000011732026/10/01 09:33:55 OK 1_commit_pending_closure.sql (1.29ms)11742026/10/01 09:33:55 OK 2_object_stats_trigger.sql (275.75µs)11752026/10/01 09:33:55 OK 3_commit_push.sql (230.54µs)11762026/10/01 09:33:55 goose: up to current file version: 311772026/10/01 09:33:55 INFO Received uploads request method=POST path=/api/pending_closures1178--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.64s)1179=== CONT TestClientFallsBackToClosures11802026-10-01 09:33:55.824 UTC [41238] ERROR: relation "goose_db_version" does not exist at character 3611812026-10-01 09:33:55.824 UTC [41238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11822026-10-01 09:33:55.850 UTC [41239] ERROR: relation "goose_db_version" does not exist at character 3611832026-10-01 09:33:55.850 UTC [41239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11842026/10/01 09:33:55 INFO Received uploads request method=POST path=/api/pending_closures11852026/10/01 09:33:55 OK 20241026095416_initial_model.sql (74.19ms)11862026/10/01 09:33:55 OK 20251210153512_drop_unused_gin_index.sql (13.25ms)11872026/10/01 09:33:55 INFO Aborted multipart uploads count=011882026/10/01 09:33:55 WARN Force mode enabled - objects will be deleted immediately without grace period11892026/10/01 09:33:55 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=011902026/10/01 09:33:55 INFO Vacuumed table table=pending_closures11912026/10/01 09:33:55 OK 20251218171726_add_pins.sql (27.12ms)11922026/10/01 09:33:55 INFO Vacuumed table table=pending_objects11932026/10/01 09:33:55 INFO Vacuumed table table=multipart_uploads11942026/10/01 09:33:55 INFO Vacuumed table table=closures11952026/10/01 09:33:56 INFO Vacuumed table table=objects11962026/10/01 09:33:56 OK 20241026095416_initial_model.sql (94.99ms)11972026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (34.38ms)11982026/10/01 09:33:56 OK 20251210153512_drop_unused_gin_index.sql (12.71ms)1199--- PASS: TestGCSweepSkipsPendingObjects (1.82s)1200=== CONT TestService_readinessHandler12012026/10/01 09:33:56 OK 20251218171726_add_pins.sql (6.16ms)12022026/10/01 09:33:56 OK 20260905000000_add_claims.sql (21.56ms)12032026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (22.77ms)12042026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (26.49ms)12052026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (7.63ms)12062026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000012072026/10/01 09:33:56 OK 1_commit_pending_closure.sql (2.48ms)12082026/10/01 09:33:56 OK 2_object_stats_trigger.sql (523.25µs)12092026/10/01 09:33:56 OK 3_commit_push.sql (301.79µs)12102026/10/01 09:33:56 goose: up to current file version: 312112026/10/01 09:33:56 OK 20260905000000_add_claims.sql (33.64ms)12122026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (13.84ms)12132026/10/01 09:33:56 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (4.39ms)12152026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000012162026/10/01 09:33:56 OK 1_commit_pending_closure.sql (2.22ms)12172026/10/01 09:33:56 OK 2_object_stats_trigger.sql (514.21µs)12182026/10/01 09:33:56 OK 3_commit_push.sql (423.96µs)12192026/10/01 09:33:56 goose: up to current file version: 31220--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.81s)1221=== CONT TestParseSingleRange1222=== RUN TestParseSingleRange/none1223=== PAUSE TestParseSingleRange/none1224=== RUN TestParseSingleRange/unknown_unit1225=== PAUSE TestParseSingleRange/unknown_unit1226=== RUN TestParseSingleRange/multi-range_ignored1227=== PAUSE TestParseSingleRange/multi-range_ignored1228=== RUN TestParseSingleRange/malformed_no_dash1229=== PAUSE TestParseSingleRange/malformed_no_dash1230=== RUN TestParseSingleRange/malformed_both_empty1231=== PAUSE TestParseSingleRange/malformed_both_empty1232=== RUN TestParseSingleRange/malformed_end_before_start1233=== PAUSE TestParseSingleRange/malformed_end_before_start1234=== RUN TestParseSingleRange/closed1235=== PAUSE TestParseSingleRange/closed1236=== RUN TestParseSingleRange/open-ended1237=== PAUSE TestParseSingleRange/open-ended1238=== RUN TestParseSingleRange/end_clamped_to_size1239=== PAUSE TestParseSingleRange/end_clamped_to_size1240=== RUN TestParseSingleRange/suffix1241=== PAUSE TestParseSingleRange/suffix1242=== RUN TestParseSingleRange/suffix_exceeds_size1243=== PAUSE TestParseSingleRange/suffix_exceeds_size1244=== RUN TestParseSingleRange/single_byte1245=== PAUSE TestParseSingleRange/single_byte1246=== RUN TestParseSingleRange/start_past_EOF1247=== PAUSE TestParseSingleRange/start_past_EOF1248=== RUN TestParseSingleRange/start_far_past_EOF1249=== PAUSE TestParseSingleRange/start_far_past_EOF1250=== CONT TestPresentNotReportedWhileGCDeletesClosure12512026-10-01 09:33:56.205 UTC [41245] ERROR: relation "goose_db_version" does not exist at character 3612522026-10-01 09:33:56.205 UTC [41245] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/10/01 09:33:56 OK 20241026095416_initial_model.sql (133.59ms)12542026/10/01 09:33:56 INFO Received uploads request method=POST path=/api/pending_closures12552026/10/01 09:33:56 OK 20251210153512_drop_unused_gin_index.sql (18.93ms)12562026/10/01 09:33:56 OK 20251218171726_add_pins.sql (38.33ms)12572026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (45.33ms)12582026/10/01 09:33:56 INFO Aborted multipart uploads count=012592026/10/01 09:33:56 OK 20260905000000_add_claims.sql (33.46ms)12602026/10/01 09:33:56 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=012612026/10/01 09:33:56 INFO Aborted multipart uploads count=012622026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (17.37ms)12632026/10/01 09:33:56 INFO Vacuumed table table=pending_closures12642026/10/01 09:33:56 WARN Force mode enabled - objects will be deleted immediately without grace period12652026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (8.51ms)12662026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000012672026/10/01 09:33:56 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=012682026/10/01 09:33:56 INFO Vacuumed table table=pending_closures12692026/10/01 09:33:56 OK 1_commit_pending_closure.sql (3.04ms)12702026/10/01 09:33:56 OK 2_object_stats_trigger.sql (560.25µs)12712026/10/01 09:33:56 OK 3_commit_push.sql (352.08µs)12722026/10/01 09:33:56 goose: up to current file version: 312732026/10/01 09:33:56 INFO Vacuumed table table=pending_objects12742026/10/01 09:33:56 INFO Vacuumed table table=multipart_uploads12752026/10/01 09:33:56 INFO Vacuumed table table=closures12762026/10/01 09:33:56 INFO Vacuumed table table=pending_objects12772026/10/01 09:33:56 INFO Vacuumed table table=objects12782026/10/01 09:33:56 INFO Vacuumed table table=multipart_uploads1279--- PASS: TestGCMetrics (1.81s)1280=== CONT TestPresentReportsOnlyClosureRoots12812026/10/01 09:33:56 INFO Vacuumed table table=closures12822026/10/01 09:33:56 INFO Vacuumed table table=objects12832026/10/01 09:33:56 INFO Aborted multipart uploads count=012842026/10/01 09:33:56 WARN Force mode enabled - objects will be deleted immediately without grace period12852026/10/01 09:33:56 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=012862026/10/01 09:33:56 INFO Vacuumed table table=pending_closures12872026/10/01 09:33:56 INFO Vacuumed table table=pending_objects12882026/10/01 09:33:56 INFO Vacuumed table table=multipart_uploads12892026/10/01 09:33:56 INFO Vacuumed table table=closures12902026/10/01 09:33:56 INFO Vacuumed table table=objects1291--- PASS: TestPushDedupSurvivesConcurrentGC (1.88s)1292=== CONT TestCreatePin_ReservedPins12932026-10-01 09:33:56.617 UTC [41251] ERROR: relation "goose_db_version" does not exist at character 3612942026-10-01 09:33:56.617 UTC [41251] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12952026-10-01 09:33:56.687 UTC [41252] ERROR: relation "goose_db_version" does not exist at character 3612962026-10-01 09:33:56.687 UTC [41252] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/10/01 09:33:56 OK 20241026095416_initial_model.sql (77.63ms)12982026/10/01 09:33:56 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)12992026/10/01 09:33:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65461/oidc13002026/10/01 09:33:56 OK 20251218171726_add_pins.sql (16.33ms)13012026-10-01 09:33:56.738 UTC [41253] ERROR: relation "goose_db_version" does not exist at character 3613022026-10-01 09:33:56.738 UTC [41253] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13032026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (14.88ms)13042026-10-01 09:33:56.758 UTC [41256] ERROR: relation "goose_db_version" does not exist at character 3613052026-10-01 09:33:56.758 UTC [41256] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13062026/10/01 09:33:56 OK 20260905000000_add_claims.sql (5.45ms)13072026/10/01 09:33:56 OK 20241026095416_initial_model.sql (38.26ms)13082026/10/01 09:33:56 OK 20251210153512_drop_unused_gin_index.sql (657.08µs)13092026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (1.09ms)13102026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (455.92µs)13112026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000013122026/10/01 09:33:56 OK 20251218171726_add_pins.sql (836.5µs)13132026/10/01 09:33:56 OK 1_commit_pending_closure.sql (867.58µs)13142026/10/01 09:33:56 OK 2_object_stats_trigger.sql (220.54µs)13152026/10/01 09:33:56 OK 3_commit_push.sql (172.79µs)13162026/10/01 09:33:56 goose: up to current file version: 313172026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (19.5ms)13182026/10/01 09:33:56 OK 20260905000000_add_claims.sql (13.11ms)13192026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (1.16ms)13202026/10/01 09:33:56 OK 20241026095416_initial_model.sql (36.32ms)13212026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (700.67µs)13222026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000013232026/10/01 09:33:56 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)13242026/10/01 09:33:56 OK 1_commit_pending_closure.sql (1.07ms)13252026/10/01 09:33:56 OK 2_object_stats_trigger.sql (206.63µs)13262026/10/01 09:33:56 OK 3_commit_push.sql (185.88µs)13272026/10/01 09:33:56 goose: up to current file version: 313282026/10/01 09:33:56 OK 20251218171726_add_pins.sql (12.03ms)13292026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (10.69ms)13302026/10/01 09:33:56 OK 20241026095416_initial_model.sql (44.5ms)13312026/10/01 09:33:56 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)13322026/10/01 09:33:56 OK 20260905000000_add_claims.sql (13.17ms)13332026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (8.22ms)13342026/10/01 09:33:56 OK 20251218171726_add_pins.sql (8.73ms)13352026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (5.83ms)13362026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000013372026/10/01 09:33:56 OK 1_commit_pending_closure.sql (1.62ms)13382026/10/01 09:33:56 OK 2_object_stats_trigger.sql (212.42µs)13392026/10/01 09:33:56 OK 3_commit_push.sql (202.88µs)13402026/10/01 09:33:56 goose: up to current file version: 313412026/10/01 09:33:56 OK 20260628120000_add_object_size_and_stats.sql (14.18ms)13422026/10/01 09:33:56 OK 20260905000000_add_claims.sql (25.37ms)13432026/10/01 09:33:56 OK 20260920000000_drop_claims.sql (11.45ms)13442026/10/01 09:33:56 OK 20260923120000_add_pushes.sql (6.73ms)13452026/10/01 09:33:56 goose: successfully migrated database to version: 2026092312000013462026/10/01 09:33:56 OK 1_commit_pending_closure.sql (1.09ms)13472026/10/01 09:33:56 OK 2_object_stats_trigger.sql (253.46µs)13482026/10/01 09:33:56 OK 3_commit_push.sql (198.29µs)13492026/10/01 09:33:56 goose: up to current file version: 313502026/10/01 09:33:56 INFO lead: acquired remote=192.0.2.1:123413512026/10/01 09:33:56 INFO lead: released remote=192.0.2.1:12341352--- PASS: TestLeadEndsOnShutdown (1.51s)1353=== CONT TestOrphanedObjectsGCStressTest1354--- PASS: TestGCBugBareHashReferences (1.74s)1355=== CONT TestOrphanedObjectsGC13562026-10-01 09:33:57.038 UTC [41264] ERROR: relation "goose_db_version" does not exist at character 3613572026-10-01 09:33:57.038 UTC [41264] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13582026/10/01 09:33:57 INFO lead: acquired remote=192.0.2.1:123413592026-10-01 09:33:57.154 UTC [41266] ERROR: relation "goose_db_version" does not exist at character 3613602026-10-01 09:33:57.154 UTC [41266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026/10/01 09:33:57 OK 20241026095416_initial_model.sql (65.2ms)13622026/10/01 09:33:57 OK 20251210153512_drop_unused_gin_index.sql (12.05ms)13632026/10/01 09:33:57 OK 20251218171726_add_pins.sql (16.45ms)13642026/10/01 09:33:57 OK 20260628120000_add_object_size_and_stats.sql (21.24ms)13652026/10/01 09:33:57 INFO lead: released remote=192.0.2.1:123413662026/10/01 09:33:57 OK 20260905000000_add_claims.sql (42.8ms)13672026/10/01 09:33:57 OK 20241026095416_initial_model.sql (87.71ms)13682026/10/01 09:33:57 OK 20260920000000_drop_claims.sql (14.52ms)13692026/10/01 09:33:57 OK 20251210153512_drop_unused_gin_index.sql (12.26ms)13702026/10/01 09:33:57 INFO lead: acquired remote=192.0.2.1:123413712026/10/01 09:33:57 INFO lead: released remote=192.0.2.1:12341372--- PASS: TestLeadElectsOneAndHandsOver (1.76s)1373=== CONT TestObjectStatsTrigger13742026/10/01 09:33:57 OK 20260923120000_add_pushes.sql (17.85ms)13752026/10/01 09:33:57 goose: successfully migrated database to version: 2026092312000013762026/10/01 09:33:57 OK 1_commit_pending_closure.sql (2.82ms)13772026/10/01 09:33:57 OK 2_object_stats_trigger.sql (636.58µs)13782026/10/01 09:33:57 OK 3_commit_push.sql (412µs)13792026/10/01 09:33:57 goose: up to current file version: 313802026/10/01 09:33:57 OK 20251218171726_add_pins.sql (34.2ms)13812026/10/01 09:33:57 OK 20260628120000_add_object_size_and_stats.sql (12.47ms)13822026/10/01 09:33:57 OK 20260905000000_add_claims.sql (20.3ms)13832026/10/01 09:33:57 OK 20260920000000_drop_claims.sql (15.5ms)13842026/10/01 09:33:57 OK 20260923120000_add_pushes.sql (13.94ms)13852026/10/01 09:33:57 goose: successfully migrated database to version: 2026092312000013862026/10/01 09:33:57 OK 1_commit_pending_closure.sql (2.93ms)13872026/10/01 09:33:57 OK 2_object_stats_trigger.sql (617.63µs)13882026/10/01 09:33:57 OK 3_commit_push.sql (407.75µs)13892026/10/01 09:33:57 goose: up to current file version: 313902026-10-01 09:33:57.481 UTC [41270] ERROR: relation "goose_db_version" does not exist at character 3613912026-10-01 09:33:57.481 UTC [41270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13922026/10/01 09:33:57 OK 20241026095416_initial_model.sql (74.89ms)13932026/10/01 09:33:57 OK 20251210153512_drop_unused_gin_index.sql (14.66ms)13942026/10/01 09:33:57 OK 20251218171726_add_pins.sql (18.48ms)13952026-10-01 09:33:57.656 UTC [41275] ERROR: relation "goose_db_version" does not exist at character 3613962026-10-01 09:33:57.656 UTC [41275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13972026/10/01 09:33:57 WARN readiness check failed error="closed pool"1398--- PASS: TestService_readinessHandler (1.64s)1399=== CONT TestMultipartCleanup14002026/10/01 09:33:57 OK 20260628120000_add_object_size_and_stats.sql (25.61ms)14012026/10/01 09:33:57 OK 20260905000000_add_claims.sql (28.9ms)14022026/10/01 09:33:57 OK 20260920000000_drop_claims.sql (6.95ms)14032026/10/01 09:33:57 OK 20260923120000_add_pushes.sql (7.01ms)14042026/10/01 09:33:57 goose: successfully migrated database to version: 2026092312000014052026/10/01 09:33:57 OK 1_commit_pending_closure.sql (1.38ms)14062026/10/01 09:33:57 OK 2_object_stats_trigger.sql (237.5µs)14072026/10/01 09:33:57 OK 3_commit_push.sql (161.54µs)14082026/10/01 09:33:57 goose: up to current file version: 314092026/10/01 09:33:57 OK 20241026095416_initial_model.sql (45.79ms)14102026/10/01 09:33:57 OK 20251210153512_drop_unused_gin_index.sql (8.43ms)14112026/10/01 09:33:57 OK 20251218171726_add_pins.sql (7.06ms)14122026/10/01 09:33:57 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/01 09:33:57 OK 20260628120000_add_object_size_and_stats.sql (33.07ms)14142026/10/01 09:33:57 INFO Received uploads request method=POST path=/api/pending_closures14152026/10/01 09:33:57 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14162026/10/01 09:33:57 INFO Uploading kzdzmxj88qbgfv2awn637h3bb1982wfv-shared-dep (136B)14172026/10/01 09:33:57 INFO Uploading lbkgz7lchi5p1sb3ncqayfrngvj9yn7m-b (248B)14182026/10/01 09:33:57 WARN Rate limiter enabled after throttle name=s3-test rate=514192026/10/01 09:33:57 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1420=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1421 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101422 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001423--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.31s)1424=== CONT TestServerTLSConfig1425=== RUN TestServerTLSConfig/no_client_CA1426=== PAUSE TestServerTLSConfig/no_client_CA1427=== RUN TestServerTLSConfig/missing_CA_file1428=== PAUSE TestServerTLSConfig/missing_CA_file1429=== RUN TestServerTLSConfig/not_a_PEM_file1430=== PAUSE TestServerTLSConfig/not_a_PEM_file1431=== CONT TestService_NativeMTLS14322026/10/01 09:33:57 OK 20260905000000_add_claims.sql (24.32ms)14332026/10/01 09:33:57 WARN Failed to register uploaded object key=kzdzmxj88qbgfv2awn637h3bb1982wfv.ls error="server returned 404: 404 page not found\n"14342026/10/01 09:33:57 WARN Failed to register uploaded object key=nar/0jdil4mifw43xaim9fmbw63zg4rbcg5yhwymzm5iayc7va8y51l3.nar.zst error="server returned 404: 404 page not found\n"14352026/10/01 09:33:57 WARN Failed to register uploaded object key=ff3n0xvs9l9vdfz60vrglzzl1ma7zwjc.ls error="server returned 404: 404 page not found\n"14362026/10/01 09:33:57 WARN Failed to register uploaded object key=lbkgz7lchi5p1sb3ncqayfrngvj9yn7m.ls error="server returned 404: 404 page not found\n"14372026/10/01 09:33:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14382026/10/01 09:33:57 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14392026/10/01 09:33:57 INFO Signed narinfos id=2 count=214402026/10/01 09:33:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14412026/10/01 09:33:57 INFO Signed narinfos id=1 count=214422026/10/01 09:33:57 INFO Uploading 4 narinfos14432026/10/01 09:33:57 OK 20260920000000_drop_claims.sql (24.25ms)14442026/10/01 09:33:57 WARN Failed to register uploaded object key=lbkgz7lchi5p1sb3ncqayfrngvj9yn7m.narinfo error="server returned 404: 404 page not found\n"14452026/10/01 09:33:57 WARN Failed to register uploaded object key=ff3n0xvs9l9vdfz60vrglzzl1ma7zwjc.narinfo error="server returned 404: 404 page not found\n"14462026/10/01 09:33:57 WARN Failed to register uploaded object key=kzdzmxj88qbgfv2awn637h3bb1982wfv.narinfo error="server returned 404: 404 page not found\n"14472026/10/01 09:33:57 OK 20260923120000_add_pushes.sql (7.51ms)14482026/10/01 09:33:57 goose: successfully migrated database to version: 2026092312000014492026/10/01 09:33:57 OK 1_commit_pending_closure.sql (1.04ms)14502026/10/01 09:33:57 OK 2_object_stats_trigger.sql (204.08µs)14512026/10/01 09:33:57 OK 3_commit_push.sql (169.25µs)14522026/10/01 09:33:57 goose: up to current file version: 314532026/10/01 09:33:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14542026/10/01 09:33:57 WARN Failed to register uploaded object key=kzdzmxj88qbgfv2awn637h3bb1982wfv.narinfo error="server returned 404: 404 page not found\n"14552026-10-01 09:33:57.889 UTC [41289] ERROR: relation "goose_db_version" does not exist at character 3614562026-10-01 09:33:57.889 UTC [41289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14572026/10/01 09:33:57 INFO Completed upload id=114582026/10/01 09:33:57 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14592026/10/01 09:33:57 INFO Completed upload id=214602026/10/01 09:33:57 INFO Upload complete. (150ms)1461=== NAME TestClientFallsBackToClosures1462 client_pushes_test.go:112: Retrieved narinfo from S3:1463 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientFallsBackToClosures1552734385/001/store/kzdzmxj88qbgfv2awn637h3bb1982wfv-shared-dep1464 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1465 Compression: zstd1466 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821467 NarSize: 1361468 References: 1469 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1470 client_pushes_test.go:112: Retrieved narinfo from S3:1471 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientFallsBackToClosures1552734385/001/store/ff3n0xvs9l9vdfz60vrglzzl1ma7zwjc-a1472 URL: nar/0jdil4mifw43xaim9fmbw63zg4rbcg5yhwymzm5iayc7va8y51l3.nar.zst1473 Compression: zstd1474 NarHash: sha256:0jdil4mifw43xaim9fmbw63zg4rbcg5yhwymzm5iayc7va8y51l31475 NarSize: 2481476 References: /nix/var/nix/builds/nix-41057-1805751233/TestClientFallsBackToClosures1552734385/001/store/kzdzmxj88qbgfv2awn637h3bb1982wfv-shared-dep1477 CA: text:sha256:1y76q5w1gabbk4b4ycla9n1b10v5ixkbfrwfm4hwz0ygpbxlfmws1478 client_pushes_test.go:112: Retrieved narinfo from S3:1479 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientFallsBackToClosures1552734385/001/store/lbkgz7lchi5p1sb3ncqayfrngvj9yn7m-b1480 URL: nar/0jdil4mifw43xaim9fmbw63zg4rbcg5yhwymzm5iayc7va8y51l3.nar.zst1481 Compression: zstd1482 NarHash: sha256:0jdil4mifw43xaim9fmbw63zg4rbcg5yhwymzm5iayc7va8y51l31483 NarSize: 2481484 References: /nix/var/nix/builds/nix-41057-1805751233/TestClientFallsBackToClosures1552734385/001/store/kzdzmxj88qbgfv2awn637h3bb1982wfv-shared-dep1485 CA: text:sha256:1y76q5w1gabbk4b4ycla9n1b10v5ixkbfrwfm4hwz0ygpbxlfmws1486--- PASS: TestClientFallsBackToClosures (2.20s)1487=== CONT TestMetricsInventory14882026-10-01 09:33:58.010 UTC [41293] ERROR: relation "goose_db_version" does not exist at character 3614892026-10-01 09:33:58.010 UTC [41293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14902026/10/01 09:33:58 OK 20241026095416_initial_model.sql (97.7ms)14912026/10/01 09:33:58 OK 20251210153512_drop_unused_gin_index.sql (10.67ms)14922026/10/01 09:33:58 OK 20251218171726_add_pins.sql (9.6ms)1493--- PASS: TestPresentReportsOnlyClosureRoots (1.50s)1494=== CONT TestNARDeduplicationMetadataUploadBug14952026/10/01 09:33:58 OK 20260628120000_add_object_size_and_stats.sql (45.67ms)1496--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.51s)1497=== CONT TestCreatePendingClosureRejectsOversizedNAR14982026/10/01 09:33:58 INFO Received uploads request method=POST path=/api/pending_closures1499--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1500=== CONT TestCacheConfigHandlerMaxNarSize1501--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1502=== CONT TestGenerateLandingPage1503--- PASS: TestGenerateLandingPage (0.00s)1504=== CONT TestCompletedNarNotReofferedAcrossClosures15052026/10/01 09:33:58 OK 20260905000000_add_claims.sql (48.95ms)15062026/10/01 09:33:58 OK 20260920000000_drop_claims.sql (32.5ms)15072026/10/01 09:33:58 OK 20260923120000_add_pushes.sql (11.57ms)15082026/10/01 09:33:58 goose: successfully migrated database to version: 2026092312000015092026/10/01 09:33:58 OK 1_commit_pending_closure.sql (1.33ms)15102026/10/01 09:33:58 OK 2_object_stats_trigger.sql (263.96µs)15112026/10/01 09:33:58 OK 3_commit_push.sql (230.5µs)15122026/10/01 09:33:58 goose: up to current file version: 315132026/10/01 09:33:58 OK 20241026095416_initial_model.sql (160.83ms)15142026/10/01 09:33:58 OK 20251210153512_drop_unused_gin_index.sql (10.04ms)15152026/10/01 09:33:58 OK 20251218171726_add_pins.sql (18.06ms)15162026/10/01 09:33:58 OK 20260628120000_add_object_size_and_stats.sql (40.21ms)15172026/10/01 09:33:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15182026/10/01 09:33:58 WARN Refused reserved pin name=worker-x86_64-linux15192026/10/01 09:33:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15202026/10/01 09:33:58 INFO Received create pin request method=POST path=/api/pins/my-app15212026/10/01 09:33:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1522--- PASS: TestCreatePin_ReservedPins (1.70s)1523=== CONT TestCacheStatsHandler1524--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.28s)1525=== CONT TestPinProtectsFromGC15262026/10/01 09:33:58 OK 20260905000000_add_claims.sql (128.43ms)15272026/10/01 09:33:58 OK 20260920000000_drop_claims.sql (24.76ms)15282026/10/01 09:33:58 OK 20260923120000_add_pushes.sql (18.97ms)15292026/10/01 09:33:58 goose: successfully migrated database to version: 2026092312000015302026/10/01 09:33:58 OK 1_commit_pending_closure.sql (1.9ms)15312026/10/01 09:33:58 OK 2_object_stats_trigger.sql (426.67µs)15322026/10/01 09:33:58 OK 3_commit_push.sql (360.79µs)15332026/10/01 09:33:58 goose: up to current file version: 315342026-10-01 09:33:58.843 UTC [41302] ERROR: relation "goose_db_version" does not exist at character 3615352026-10-01 09:33:58.843 UTC [41302] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15362026/10/01 09:33:59 OK 20241026095416_initial_model.sql (158.39ms)15372026/10/01 09:33:59 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)15382026/10/01 09:33:59 OK 20251218171726_add_pins.sql (19.46ms)15392026/10/01 09:33:59 OK 20260628120000_add_object_size_and_stats.sql (24.6ms)15402026/10/01 09:33:59 OK 20260905000000_add_claims.sql (46.75ms)15412026/10/01 09:33:59 OK 20260920000000_drop_claims.sql (43.15ms)15422026/10/01 09:33:59 OK 20260923120000_add_pushes.sql (19.15ms)15432026/10/01 09:33:59 goose: successfully migrated database to version: 2026092312000015442026/10/01 09:33:59 OK 1_commit_pending_closure.sql (4.33ms)15452026/10/01 09:33:59 OK 2_object_stats_trigger.sql (736.29µs)15462026/10/01 09:33:59 OK 3_commit_push.sql (1.72ms)15472026/10/01 09:33:59 goose: up to current file version: 315482026-10-01 09:33:59.735 UTC [41303] ERROR: relation "goose_db_version" does not exist at character 3615492026-10-01 09:33:59.735 UTC [41303] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1550--- PASS: TestObjectStatsTrigger (2.46s)1551=== CONT TestClientSharedPathCommittedMidPush1552=== NAME TestOrphanedObjectsGC1553 orphaned_objects_gc_test.go:290: GC Test Summary:1554 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1555 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1556 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1557 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1558 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1559--- PASS: TestOrphanedObjectsGC (2.98s)1560=== CONT TestClientWithDependencies15612026/10/01 09:34:00 OK 20241026095416_initial_model.sql (225.58ms)15622026/10/01 09:34:00 OK 20251210153512_drop_unused_gin_index.sql (15.41ms)15632026/10/01 09:34:00 OK 20251218171726_add_pins.sql (37.73ms)15642026-10-01 09:34:00.082 UTC [41309] ERROR: relation "goose_db_version" does not exist at character 3615652026-10-01 09:34:00.082 UTC [41309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15662026/10/01 09:34:00 OK 20260628120000_add_object_size_and_stats.sql (31.64ms)15672026/10/01 09:34:00 OK 20260905000000_add_claims.sql (67.43ms)15682026-10-01 09:34:00.210 UTC [41312] ERROR: relation "goose_db_version" does not exist at character 3615692026-10-01 09:34:00.210 UTC [41312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15702026/10/01 09:34:00 OK 20260920000000_drop_claims.sql (33.86ms)15712026/10/01 09:34:00 OK 20260923120000_add_pushes.sql (10.32ms)15722026/10/01 09:34:00 goose: successfully migrated database to version: 2026092312000015732026/10/01 09:34:00 OK 1_commit_pending_closure.sql (3.69ms)15742026/10/01 09:34:00 OK 2_object_stats_trigger.sql (631.75µs)15752026/10/01 09:34:00 OK 3_commit_push.sql (419.96µs)15762026/10/01 09:34:00 goose: up to current file version: 315772026/10/01 09:34:00 OK 20241026095416_initial_model.sql (225.83ms)15782026/10/01 09:34:00 OK 20251210153512_drop_unused_gin_index.sql (10.57ms)15792026/10/01 09:34:00 OK 20251218171726_add_pins.sql (35.92ms)15802026/10/01 09:34:00 OK 20260628120000_add_object_size_and_stats.sql (57.89ms)15812026/10/01 09:34:00 OK 20241026095416_initial_model.sql (306.02ms)15822026/10/01 09:34:00 OK 20260905000000_add_claims.sql (112.93ms)15832026/10/01 09:34:00 OK 20251210153512_drop_unused_gin_index.sql (17.2ms)15842026/10/01 09:34:00 INFO Received uploads request method=POST path=/api/pending_closures15852026/10/01 09:34:00 OK 20251218171726_add_pins.sql (52.6ms)15862026/10/01 09:34:00 OK 20260920000000_drop_claims.sql (71.75ms)15872026/10/01 09:34:00 OK 20260923120000_add_pushes.sql (20.86ms)15882026/10/01 09:34:00 goose: successfully migrated database to version: 2026092312000015892026/10/01 09:34:00 OK 1_commit_pending_closure.sql (3.55ms)15902026/10/01 09:34:00 OK 2_object_stats_trigger.sql (770.17µs)15912026/10/01 09:34:00 OK 3_commit_push.sql (519.58µs)15922026/10/01 09:34:00 goose: up to current file version: 315932026/10/01 09:34:00 OK 20260628120000_add_object_size_and_stats.sql (35.12ms)15942026/10/01 09:34:00 OK 20260905000000_add_claims.sql (122.52ms)15952026-10-01 09:34:00.817 UTC [41313] ERROR: relation "goose_db_version" does not exist at character 3615962026-10-01 09:34:00.817 UTC [41313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15972026/10/01 09:34:00 INFO Received cleanup request method=DELETE path=/api/pending_closures15982026/10/01 09:34:00 OK 20260920000000_drop_claims.sql (72.76ms)15992026-10-01 09:34:00.890 UTC [41314] ERROR: relation "goose_db_version" does not exist at character 3616002026-10-01 09:34:00.890 UTC [41314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16012026/10/01 09:34:00 INFO Aborted multipart uploads count=116022026/10/01 09:34:00 OK 20260923120000_add_pushes.sql (22.46ms)16032026/10/01 09:34:00 goose: successfully migrated database to version: 2026092312000016042026/10/01 09:34:00 OK 1_commit_pending_closure.sql (7ms)16052026/10/01 09:34:00 OK 2_object_stats_trigger.sql (922.08µs)16062026/10/01 09:34:00 OK 3_commit_push.sql (1.36ms)16072026/10/01 09:34:00 goose: up to current file version: 31608--- PASS: TestMultipartCleanup (3.27s)1609=== CONT TestClientMultipleUploads16102026/10/01 09:34:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16112026/10/01 09:34:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1612--- PASS: TestService_NativeMTLS (3.25s)1613=== CONT TestClientIntegration16142026/10/01 09:34:01 OK 20241026095416_initial_model.sql (288.77ms)16152026/10/01 09:34:01 OK 20251210153512_drop_unused_gin_index.sql (11.82ms)16162026/10/01 09:34:01 OK 20241026095416_initial_model.sql (272.18ms)16172026/10/01 09:34:01 OK 20251218171726_add_pins.sql (34.34ms)16182026/10/01 09:34:01 OK 20251210153512_drop_unused_gin_index.sql (16.9ms)16192026-10-01 09:34:01.309 UTC [41319] ERROR: relation "goose_db_version" does not exist at character 3616202026-10-01 09:34:01.309 UTC [41319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16212026/10/01 09:34:01 OK 20260628120000_add_object_size_and_stats.sql (58.36ms)16222026/10/01 09:34:01 OK 20251218171726_add_pins.sql (52.11ms)16232026/10/01 09:34:01 OK 20260905000000_add_claims.sql (112.49ms)16242026/10/01 09:34:01 OK 20260628120000_add_object_size_and_stats.sql (117.02ms)16252026/10/01 09:34:01 OK 20260920000000_drop_claims.sql (42.22ms)16262026/10/01 09:34:01 OK 20260923120000_add_pushes.sql (33.88ms)16272026/10/01 09:34:01 goose: successfully migrated database to version: 2026092312000016282026/10/01 09:34:01 OK 1_commit_pending_closure.sql (4.62ms)16292026/10/01 09:34:01 OK 2_object_stats_trigger.sql (1.12ms)16302026/10/01 09:34:01 OK 3_commit_push.sql (551.54µs)16312026/10/01 09:34:01 goose: up to current file version: 316322026/10/01 09:34:01 OK 20260905000000_add_claims.sql (75.21ms)16332026-10-01 09:34:01.536 UTC [41320] ERROR: relation "goose_db_version" does not exist at character 3616342026-10-01 09:34:01.536 UTC [41320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1635--- PASS: TestMetricsInventory (3.61s)1636=== CONT TestClientErrorHandling1637=== RUN TestClientErrorHandling/InvalidStorePath1638=== PAUSE TestClientErrorHandling/InvalidStorePath1639=== RUN TestClientErrorHandling/InvalidAuthToken1640=== PAUSE TestClientErrorHandling/InvalidAuthToken1641=== RUN TestClientErrorHandling/ServerNotAvailable1642=== PAUSE TestClientErrorHandling/ServerNotAvailable1643=== CONT TestClientCADerivations16442026/10/01 09:34:01 OK 20260920000000_drop_claims.sql (48.13ms)16452026/10/01 09:34:01 OK 20260923120000_add_pushes.sql (16.8ms)16462026/10/01 09:34:01 goose: successfully migrated database to version: 2026092312000016472026/10/01 09:34:01 OK 1_commit_pending_closure.sql (2.73ms)16482026/10/01 09:34:01 OK 2_object_stats_trigger.sql (540.88µs)16492026/10/01 09:34:01 OK 3_commit_push.sql (365.71µs)16502026/10/01 09:34:01 goose: up to current file version: 316512026/10/01 09:34:01 OK 20241026095416_initial_model.sql (221.53ms)16522026/10/01 09:34:01 OK 20251210153512_drop_unused_gin_index.sql (20.51ms)16532026/10/01 09:34:01 OK 20251218171726_add_pins.sql (45.51ms)16542026/10/01 09:34:01 OK 20260628120000_add_object_size_and_stats.sql (64.6ms)16552026/10/01 09:34:01 INFO Received uploads request method=POST path=/api/pending_closures16562026/10/01 09:34:01 OK 20241026095416_initial_model.sql (243.78ms)16572026/10/01 09:34:01 OK 20251210153512_drop_unused_gin_index.sql (14.1ms)16582026/10/01 09:34:01 OK 20260905000000_add_claims.sql (72.5ms)16592026/10/01 09:34:01 OK 20251218171726_add_pins.sql (55.25ms)16602026/10/01 09:34:01 OK 20260920000000_drop_claims.sql (64.43ms)16612026/10/01 09:34:01 OK 20260628120000_add_object_size_and_stats.sql (41.2ms)16622026/10/01 09:34:01 OK 20260923120000_add_pushes.sql (33.95ms)16632026/10/01 09:34:01 goose: successfully migrated database to version: 2026092312000016642026/10/01 09:34:01 OK 1_commit_pending_closure.sql (5.36ms)16652026/10/01 09:34:01 OK 2_object_stats_trigger.sql (1.09ms)16662026/10/01 09:34:01 OK 3_commit_push.sql (613.13µs)16672026/10/01 09:34:01 goose: up to current file version: 316682026/10/01 09:34:02 OK 20260905000000_add_claims.sql (91.91ms)16692026/10/01 09:34:02 OK 20260920000000_drop_claims.sql (57.39ms)16702026/10/01 09:34:02 OK 20260923120000_add_pushes.sql (29.6ms)16712026/10/01 09:34:02 goose: successfully migrated database to version: 2026092312000016722026/10/01 09:34:02 OK 1_commit_pending_closure.sql (4.92ms)16732026/10/01 09:34:02 OK 2_object_stats_trigger.sql (2.13ms)16742026/10/01 09:34:02 OK 3_commit_push.sql (827.58µs)16752026/10/01 09:34:02 goose: up to current file version: 31676=== NAME TestNARDeduplicationMetadataUploadBug1677 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-41057-1805751233/TestNARDeduplicationMetadataUploadBug1890868858/001/store/9fysx4lj3xi9yv3bqlyqnrjsv8qrcpiv-file1.txt1678--- PASS: TestCacheStatsHandler (4.31s)1679=== CONT TestService_createPendingClosureHandler16802026-10-01 09:34:02.625 UTC [41325] ERROR: relation "goose_db_version" does not exist at character 3616812026-10-01 09:34:02.625 UTC [41325] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16822026/10/01 09:34:02 INFO Received push request method=POST path=/api/pushes16832026/10/01 09:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16842026/10/01 09:34:02 INFO Uploading 9fysx4lj3xi9yv3bqlyqnrjsv8qrcpiv-file1.txt (160B)16852026/10/01 09:34:02 WARN Failed to register uploaded object key=9fysx4lj3xi9yv3bqlyqnrjsv8qrcpiv.ls error="server returned 404: 404 page not found\n"16862026/10/01 09:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16872026/10/01 09:34:02 INFO Signed narinfos id=1 count=116882026/10/01 09:34:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16892026/10/01 09:34:02 INFO Uploading 1 narinfos16902026/10/01 09:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete16912026/10/01 09:34:02 WARN Failed to register uploaded object key=9fysx4lj3xi9yv3bqlyqnrjsv8qrcpiv.narinfo error="server returned 404: 404 page not found\n"16922026-10-01 09:34:02.806 UTC [41332] ERROR: relation "goose_db_version" does not exist at character 3616932026-10-01 09:34:02.806 UTC [41332] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16942026/10/01 09:34:02 INFO Upload complete. (187ms)1695=== NAME TestNARDeduplicationMetadataUploadBug1696 metadata_upload_test.go:54: Retrieved narinfo from S3:1697 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestNARDeduplicationMetadataUploadBug1890868858/001/store/9fysx4lj3xi9yv3bqlyqnrjsv8qrcpiv-file1.txt1698 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1699 Compression: zstd1700 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1701 NarSize: 1601702 References: 1703 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1704 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1705 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1706 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17072026/10/01 09:34:02 OK 20241026095416_initial_model.sql (177.82ms)17082026/10/01 09:34:02 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)17092026/10/01 09:34:02 OK 20251218171726_add_pins.sql (29.59ms)17102026/10/01 09:34:02 OK 20260628120000_add_object_size_and_stats.sql (32.24ms)1711 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-41057-1805751233/TestNARDeduplicationMetadataUploadBug1890868858/001/store/290nj1fn0dclny8j7xwi5akikm91pri4-file2.txt17122026/10/01 09:34:02 OK 20260905000000_add_claims.sql (16.59ms)17132026/10/01 09:34:02 OK 20241026095416_initial_model.sql (101.52ms)17142026/10/01 09:34:02 OK 20260920000000_drop_claims.sql (19.69ms)17152026/10/01 09:34:02 OK 20251210153512_drop_unused_gin_index.sql (7.41ms)17162026/10/01 09:34:02 OK 20260923120000_add_pushes.sql (11.1ms)17172026/10/01 09:34:02 goose: successfully migrated database to version: 2026092312000017182026/10/01 09:34:02 OK 1_commit_pending_closure.sql (1.03ms)17192026/10/01 09:34:02 OK 2_object_stats_trigger.sql (239.58µs)17202026/10/01 09:34:02 OK 3_commit_push.sql (215.46µs)17212026/10/01 09:34:02 goose: up to current file version: 317222026/10/01 09:34:03 OK 20251218171726_add_pins.sql (32.11ms)17232026/10/01 09:34:03 OK 20260628120000_add_object_size_and_stats.sql (41.94ms)17242026/10/01 09:34:03 INFO Received push request method=POST path=/api/pushes17252026/10/01 09:34:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17262026/10/01 09:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17272026/10/01 09:34:03 WARN Failed to register uploaded object key=290nj1fn0dclny8j7xwi5akikm91pri4.ls error="server returned 404: 404 page not found\n"17282026/10/01 09:34:03 INFO Signed narinfos id=2 count=117292026/10/01 09:34:03 INFO Uploading 1 narinfos17302026/10/01 09:34:03 INFO Received complete push request method=POST path=/api/pushes/2/complete17312026/10/01 09:34:03 WARN Failed to register uploaded object key=290nj1fn0dclny8j7xwi5akikm91pri4.narinfo error="server returned 404: 404 page not found\n"17322026/10/01 09:34:03 INFO Upload complete. (111ms)1733 metadata_upload_test.go:76: Retrieved narinfo from S3:1734 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestNARDeduplicationMetadataUploadBug1890868858/001/store/290nj1fn0dclny8j7xwi5akikm91pri4-file2.txt1735 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1736 Compression: zstd1737 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1738 NarSize: 1601739 References: 1740 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1741 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1742 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1743 {"version":1,"root":{"type":"regular","size":44}}17442026/10/01 09:34:03 OK 20260905000000_add_claims.sql (74.14ms)1745=== NAME TestPinProtectsFromGC1746 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-41057-1805751233/TestPinProtectsFromGC1568531407/001/store/n0ahbw7d65wxqpznidwhbsgww8zy04hy-pinned-file.txt1747 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-41057-1805751233/TestPinProtectsFromGC1568531407/001/store/1q1hlbgb2jqhnlic26r54jyki27vsmns-unpinned-file.txt17482026/10/01 09:34:03 OK 20260920000000_drop_claims.sql (49.57ms)1749--- PASS: TestNARDeduplicationMetadataUploadBug (5.18s)1750=== CONT TestCompleteMultipartUnregistered17512026/10/01 09:34:03 OK 20260923120000_add_pushes.sql (54.07ms)17522026/10/01 09:34:03 goose: successfully migrated database to version: 2026092312000017532026/10/01 09:34:03 OK 1_commit_pending_closure.sql (1.03ms)17542026/10/01 09:34:03 OK 2_object_stats_trigger.sql (284.75µs)17552026/10/01 09:34:03 OK 3_commit_push.sql (171.75µs)17562026/10/01 09:34:03 goose: up to current file version: 317572026/10/01 09:34:03 INFO Received push request method=POST path=/api/pushes17582026/10/01 09:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17592026/10/01 09:34:03 INFO Uploading n0ahbw7d65wxqpznidwhbsgww8zy04hy-pinned-file.txt (128B)17602026/10/01 09:34:03 WARN Failed to register uploaded object key=n0ahbw7d65wxqpznidwhbsgww8zy04hy.ls error="server returned 404: 404 page not found\n"17612026/10/01 09:34:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17622026/10/01 09:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17632026/10/01 09:34:03 INFO Signed narinfos id=1 count=117642026/10/01 09:34:03 INFO Uploading 1 narinfos17652026/10/01 09:34:03 INFO Received complete push request method=POST path=/api/pushes/1/complete17662026/10/01 09:34:03 WARN Failed to register uploaded object key=n0ahbw7d65wxqpznidwhbsgww8zy04hy.narinfo error="server returned 404: 404 page not found\n"17672026/10/01 09:34:03 INFO Upload complete. (221ms)17682026/10/01 09:34:03 INFO Received push request method=POST path=/api/pushes17692026/10/01 09:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17702026/10/01 09:34:03 INFO Uploading 1q1hlbgb2jqhnlic26r54jyki27vsmns-unpinned-file.txt (128B)17712026/10/01 09:34:03 WARN Failed to register uploaded object key=1q1hlbgb2jqhnlic26r54jyki27vsmns.ls error="server returned 404: 404 page not found\n"17722026/10/01 09:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17732026/10/01 09:34:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17742026/10/01 09:34:03 INFO Signed narinfos id=2 count=117752026/10/01 09:34:03 INFO Uploading 1 narinfos17762026/10/01 09:34:03 INFO Received complete push request method=POST path=/api/pushes/2/complete17772026/10/01 09:34:03 WARN Failed to register uploaded object key=1q1hlbgb2jqhnlic26r54jyki27vsmns.narinfo error="server returned 404: 404 page not found\n"17782026/10/01 09:34:03 INFO Upload complete. (121ms)17792026/10/01 09:34:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures17802026/10/01 09:34:03 INFO Garbage collection started17812026/10/01 09:34:03 INFO Aborted multipart uploads count=017822026/10/01 09:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period17832026-10-01 09:34:03.639 UTC [41355] ERROR: relation "goose_db_version" does not exist at character 3617842026-10-01 09:34:03.639 UTC [41355] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17852026/10/01 09:34:03 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=017862026/10/01 09:34:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17872026/10/01 09:34:03 INFO Vacuumed table table=pending_closures17882026/10/01 09:34:03 INFO Vacuumed table table=pending_objects17892026/10/01 09:34:03 INFO Vacuumed table table=multipart_uploads17902026-10-01 09:34:03.744 UTC [41363] ERROR: relation "goose_db_version" does not exist at character 3617912026-10-01 09:34:03.744 UTC [41363] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17922026/10/01 09:34:03 INFO Vacuumed table table=closures17932026/10/01 09:34:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWJlNGYwYTYtZjc4My00ZTBiLTk2NTMtNjhiZWE3Zjk5MjBmLmE2YWIwNzFkLTY4MDAtNGNhMi05NzQ3LTY1ZTQ5NzlkZGM3OHgxNzkwODQ3MjQxODgxNjM0MDAw parts=1217942026/10/01 09:34:03 INFO Received uploads request method=POST path=/api/pending_closures1795--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.62s)1796=== CONT TestService_verifyS3Integrity17972026/10/01 09:34:03 INFO Vacuumed table table=objects17982026-10-01 09:34:03.804 UTC [41371] ERROR: relation "goose_db_version" does not exist at character 3617992026-10-01 09:34:03.804 UTC [41371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026/10/01 09:34:03 INFO Received push request method=POST path=/api/pushes18012026/10/01 09:34:03 OK 20241026095416_initial_model.sql (132.62ms)18022026/10/01 09:34:03 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)18032026/10/01 09:34:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18042026/10/01 09:34:03 INFO Uploading gkc1jc3y9y5za2byjvpsbdan0iad3glx-shared-dep (136B)18052026/10/01 09:34:03 INFO Uploading jzyd1p4h2vz24ycyckbkyv8bmw94w2np-top (256B)18062026/10/01 09:34:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18072026/10/01 09:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18082026/10/01 09:34:03 WARN Failed to register uploaded object key=nar/167049wnnb38sz95m5503hhyd0r3529aiblz6yv3c5wp203s2g8c.nar.zst error="server returned 404: 404 page not found\n"18092026/10/01 09:34:03 WARN Failed to register uploaded object key=jzyd1p4h2vz24ycyckbkyv8bmw94w2np.ls error="server returned 404: 404 page not found\n"18102026/10/01 09:34:03 WARN Failed to register uploaded object key=gkc1jc3y9y5za2byjvpsbdan0iad3glx.ls error="server returned 404: 404 page not found\n"18112026/10/01 09:34:03 OK 20251218171726_add_pins.sql (17.62ms)18122026/10/01 09:34:03 INFO Signed narinfos id=1 count=218132026/10/01 09:34:03 INFO Uploading 2 narinfos18142026/10/01 09:34:03 OK 20241026095416_initial_model.sql (68.57ms)18152026/10/01 09:34:03 OK 20251210153512_drop_unused_gin_index.sql (7.21ms)18162026/10/01 09:34:03 INFO Received complete push request method=POST path=/api/pushes/1/complete18172026/10/01 09:34:03 WARN Failed to register uploaded object key=jzyd1p4h2vz24ycyckbkyv8bmw94w2np.narinfo error="server returned 404: 404 page not found\n"18182026/10/01 09:34:03 WARN Failed to register uploaded object key=gkc1jc3y9y5za2byjvpsbdan0iad3glx.narinfo error="server returned 404: 404 page not found\n"18192026/10/01 09:34:03 OK 20251218171726_add_pins.sql (1.91ms)18202026/10/01 09:34:03 OK 20260628120000_add_object_size_and_stats.sql (17.44ms)18212026/10/01 09:34:03 INFO Upload complete. (95ms)1822=== NAME TestClientSharedPathCommittedMidPush1823 client_integration_test.go:680: Retrieved narinfo from S3:1824 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientSharedPathCommittedMidPush1164524844/001/store/gkc1jc3y9y5za2byjvpsbdan0iad3glx-shared-dep1825 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1826 Compression: zstd1827 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821828 NarSize: 1361829 References: 1830 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1831 client_integration_test.go:680: Retrieved narinfo from S3:1832 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientSharedPathCommittedMidPush1164524844/001/store/jzyd1p4h2vz24ycyckbkyv8bmw94w2np-top1833 URL: nar/167049wnnb38sz95m5503hhyd0r3529aiblz6yv3c5wp203s2g8c.nar.zst1834 Compression: zstd1835 NarHash: sha256:167049wnnb38sz95m5503hhyd0r3529aiblz6yv3c5wp203s2g8c1836 NarSize: 2561837 References: /nix/var/nix/builds/nix-41057-1805751233/TestClientSharedPathCommittedMidPush1164524844/001/store/gkc1jc3y9y5za2byjvpsbdan0iad3glx-shared-dep1838 CA: text:sha256:0sym9f83x3rkjdmymhkik490vmfls2ppx2bq6fp7q5gwa2j1q9n018392026/10/01 09:34:03 OK 20260628120000_add_object_size_and_stats.sql (19.24ms)18402026/10/01 09:34:03 OK 20260905000000_add_claims.sql (24.81ms)18412026/10/01 09:34:03 OK 20260905000000_add_claims.sql (15.13ms)1842--- PASS: TestClientSharedPathCommittedMidPush (4.14s)1843=== CONT TestUploadHandlersRejectOversizedBody18442026/10/01 09:34:03 OK 20260920000000_drop_claims.sql (10.54ms)18452026/10/01 09:34:03 OK 20260920000000_drop_claims.sql (5.46ms)18462026/10/01 09:34:03 OK 20260923120000_add_pushes.sql (4.63ms)18472026/10/01 09:34:03 goose: successfully migrated database to version: 2026092312000018482026/10/01 09:34:03 OK 1_commit_pending_closure.sql (1.62ms)18492026/10/01 09:34:03 OK 2_object_stats_trigger.sql (329.13µs)18502026/10/01 09:34:03 OK 3_commit_push.sql (230.63µs)18512026/10/01 09:34:03 goose: up to current file version: 318522026/10/01 09:34:03 OK 20260923120000_add_pushes.sql (8.46ms)18532026/10/01 09:34:03 goose: successfully migrated database to version: 2026092312000018542026/10/01 09:34:03 OK 20241026095416_initial_model.sql (57.37ms)18552026/10/01 09:34:03 OK 1_commit_pending_closure.sql (1.2ms)18562026/10/01 09:34:03 OK 2_object_stats_trigger.sql (260.29µs)18572026/10/01 09:34:03 OK 3_commit_push.sql (173.54µs)18582026/10/01 09:34:03 goose: up to current file version: 31859=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1860=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1861=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1862=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1863=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1864=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1865=== CONT TestService_cleanupPendingClosuresHandler18662026/10/01 09:34:03 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)18672026/10/01 09:34:03 OK 20251218171726_add_pins.sql (15.28ms)18682026/10/01 09:34:03 OK 20260628120000_add_object_size_and_stats.sql (33.31ms)18692026/10/01 09:34:03 OK 20260905000000_add_claims.sql (37.03ms)1870=== NAME TestClientWithDependencies1871 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-41057-1805751233/TestClientWithDependencies3367624756/001/store/7396crsfx49qx2abii2jlss041xq9gws-test-script18722026/10/01 09:34:04 OK 20260920000000_drop_claims.sql (19.86ms)18732026/10/01 09:34:04 OK 20260923120000_add_pushes.sql (7.03ms)18742026/10/01 09:34:04 goose: successfully migrated database to version: 2026092312000018752026/10/01 09:34:04 OK 1_commit_pending_closure.sql (977.21µs)18762026/10/01 09:34:04 OK 2_object_stats_trigger.sql (217.42µs)18772026/10/01 09:34:04 OK 3_commit_push.sql (192.42µs)18782026/10/01 09:34:04 goose: up to current file version: 31879 client_integration_test.go:615: Found 1 dependencies (including self)18802026/10/01 09:34:04 INFO Received push request method=POST path=/api/pushes18812026/10/01 09:34:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18822026/10/01 09:34:04 INFO Uploading 7396crsfx49qx2abii2jlss041xq9gws-test-script (136B)18832026/10/01 09:34:04 WARN Failed to register uploaded object key=7396crsfx49qx2abii2jlss041xq9gws.ls error="server returned 404: 404 page not found\n"18842026/10/01 09:34:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18852026/10/01 09:34:04 WARN Failed to register uploaded object key=log/b0zdgn0mka38yrfmhljfqw6p9d86nb5d-test-script.drv error="server returned 404: 404 page not found\n"18862026/10/01 09:34:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18872026/10/01 09:34:04 INFO Signed narinfos id=1 count=118882026/10/01 09:34:04 INFO Uploading 1 narinfos18892026/10/01 09:34:04 INFO Received complete push request method=POST path=/api/pushes/1/complete18902026/10/01 09:34:04 WARN Failed to register uploaded object key=7396crsfx49qx2abii2jlss041xq9gws.narinfo error="server returned 404: 404 page not found\n"18912026/10/01 09:34:04 INFO Upload complete. (121ms)1892 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-41057-1805751233/TestClientWithDependencies3367624756/001/store) requires matching store prefix1893--- PASS: TestClientWithDependencies (4.36s)1894=== CONT TestUploadHandlersRejectInvalidKeys1895=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1896=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1897=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1898=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1899=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1900=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1901=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1902=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1903=== CONT TestService_AuthMiddleware_OIDC19042026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49197/oidc19052026-10-01 09:34:04.338 UTC [41385] ERROR: relation "goose_db_version" does not exist at character 3619062026-10-01 09:34:04.338 UTC [41385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1907=== NAME TestClientMultipleUploads1908 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-41057-1805751233/TestClientMultipleUploads4030721241/001/store/maqi51qfqilhgj1ljh2z5cnyxdpwpcfb-test-file-0.txt1909 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-41057-1805751233/TestClientMultipleUploads4030721241/001/store/74f0yyffdi7njfy11k5y24s0i7kq4fsj-test-file-1.txt19102026/10/01 09:34:04 OK 20241026095416_initial_model.sql (112.24ms)19112026/10/01 09:34:04 OK 20251210153512_drop_unused_gin_index.sql (10.59ms)1912 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-41057-1805751233/TestClientMultipleUploads4030721241/001/store/9y4rvpzrxw2x56zpnms6f6s321cjpllx-test-file-2.txt19132026/10/01 09:34:04 OK 20251218171726_add_pins.sql (26.36ms)19142026/10/01 09:34:04 OK 20260628120000_add_object_size_and_stats.sql (44.12ms)1915=== NAME TestClientIntegration1916 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-41057-1805751233/TestClientIntegration1280826805/002/store/njg094yjh43yczigp5n3h7dm53m6zq6p-test-file.txt19172026/10/01 09:34:04 INFO Received push request method=POST path=/api/pushes19182026/10/01 09:34:04 OK 20260905000000_add_claims.sql (35.86ms)19192026/10/01 09:34:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19202026/10/01 09:34:04 INFO Uploading 74f0yyffdi7njfy11k5y24s0i7kq4fsj-test-file-1.txt (160B)19212026/10/01 09:34:04 INFO Uploading maqi51qfqilhgj1ljh2z5cnyxdpwpcfb-test-file-0.txt (160B)19222026/10/01 09:34:04 INFO Uploading 9y4rvpzrxw2x56zpnms6f6s321cjpllx-test-file-2.txt (160B)19232026/10/01 09:34:04 OK 20260920000000_drop_claims.sql (16ms)19242026/10/01 09:34:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19252026/10/01 09:34:04 WARN Failed to register uploaded object key=74f0yyffdi7njfy11k5y24s0i7kq4fsj.ls error="server returned 404: 404 page not found\n"19262026/10/01 09:34:04 WARN Failed to register uploaded object key=maqi51qfqilhgj1ljh2z5cnyxdpwpcfb.ls error="server returned 404: 404 page not found\n"19272026/10/01 09:34:04 WARN Failed to register uploaded object key=9y4rvpzrxw2x56zpnms6f6s321cjpllx.ls error="server returned 404: 404 page not found\n"19282026/10/01 09:34:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19292026/10/01 09:34:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19302026/10/01 09:34:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19312026-10-01 09:34:04.643 UTC [41401] ERROR: relation "goose_db_version" does not exist at character 3619322026-10-01 09:34:04.643 UTC [41401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19332026/10/01 09:34:04 INFO Signed narinfos id=1 count=319342026/10/01 09:34:04 INFO Uploading 3 narinfos19352026/10/01 09:34:04 OK 20260923120000_add_pushes.sql (20.05ms)19362026/10/01 09:34:04 goose: successfully migrated database to version: 2026092312000019372026/10/01 09:34:04 OK 1_commit_pending_closure.sql (947.75µs)19382026/10/01 09:34:04 OK 2_object_stats_trigger.sql (221.29µs)19392026/10/01 09:34:04 OK 3_commit_push.sql (148µs)19402026/10/01 09:34:04 goose: up to current file version: 319412026/10/01 09:34:04 WARN Failed to register uploaded object key=74f0yyffdi7njfy11k5y24s0i7kq4fsj.narinfo error="server returned 404: 404 page not found\n"19422026/10/01 09:34:04 WARN Failed to register uploaded object key=maqi51qfqilhgj1ljh2z5cnyxdpwpcfb.narinfo error="server returned 404: 404 page not found\n"19432026/10/01 09:34:04 INFO Received complete push request method=POST path=/api/pushes/1/complete19442026/10/01 09:34:04 WARN Failed to register uploaded object key=9y4rvpzrxw2x56zpnms6f6s321cjpllx.narinfo error="server returned 404: 404 page not found\n"19452026/10/01 09:34:04 INFO Received push request method=POST path=/api/pushes19462026/10/01 09:34:04 INFO Upload complete. (144ms)1947=== NAME TestClientMultipleUploads1948 client_integration_test.go:369: Uploaded 3 paths in 177.96625ms19492026/10/01 09:34:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19502026/10/01 09:34:04 INFO Uploading njg094yjh43yczigp5n3h7dm53m6zq6p-test-file.txt (152B)19512026/10/01 09:34:04 WARN Failed to register uploaded object key=njg094yjh43yczigp5n3h7dm53m6zq6p.ls error="server returned 404: 404 page not found\n"19522026/10/01 09:34:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19532026/10/01 09:34:04 INFO Signed narinfos id=1 count=119542026/10/01 09:34:04 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19552026/10/01 09:34:04 INFO Uploading 1 narinfos19562026/10/01 09:34:04 INFO Received complete push request method=POST path=/api/pushes/1/complete19572026/10/01 09:34:04 WARN Failed to register uploaded object key=njg094yjh43yczigp5n3h7dm53m6zq6p.narinfo error="server returned 404: 404 page not found\n"19582026/10/01 09:34:04 INFO Upload complete. (129ms)1959--- PASS: TestClientMultipleUploads (3.84s)1960=== CONT TestCacheConfigHandler1961=== RUN TestCacheConfigHandler/full_config,_no_issuer1962=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1963=== RUN TestCacheConfigHandler/no_cache_url_configured1964=== PAUSE TestCacheConfigHandler/no_cache_url_configured1965=== RUN TestCacheConfigHandler/no_signing_keys1966=== PAUSE TestCacheConfigHandler/no_signing_keys1967=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1968=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1969=== CONT TestService_ReadScope_PublicByDefault19702026/10/01 09:34:04 INFO All 1 paths already cached1971=== NAME TestClientIntegration1972 client_integration_test.go:312: Retrieved narinfo from S3:1973 StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientIntegration1280826805/002/store/njg094yjh43yczigp5n3h7dm53m6zq6p-test-file.txt1974 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1975 Compression: zstd1976 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11977 NarSize: 1521978 References: 1979 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11980 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1981 client_integration_test.go:313: Decompressed .ls content (64 bytes):1982 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1983 client_integration_test.go:316: Testing garbage collection...19842026/10/01 09:34:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures19852026/10/01 09:34:04 INFO Garbage collection started19862026/10/01 09:34:04 INFO Aborted multipart uploads count=019872026/10/01 09:34:04 WARN Force mode enabled - objects will be deleted immediately without grace period1988=== NAME TestOrphanedObjectsGCStressTest1989 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19902026/10/01 09:34:04 OK 20241026095416_initial_model.sql (144.39ms)19912026/10/01 09:34:04 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)19922026/10/01 09:34:04 OK 20251218171726_add_pins.sql (32.56ms)19932026/10/01 09:34:04 INFO Received uploads request method=POST path=/api/pending_closures19942026/10/01 09:34:04 INFO Received uploads request method=POST path=/api/pending_closures19952026/10/01 09:34:04 INFO Received uploads request method=POST path=/api/pending_closures19962026/10/01 09:34:04 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=01997 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19982026/10/01 09:34:04 OK 20260628120000_add_object_size_and_stats.sql (14.84ms)19992026/10/01 09:34:04 INFO Vacuumed table table=pending_closures20002026/10/01 09:34:04 INFO Vacuumed table table=pending_objects20012026/10/01 09:34:04 INFO Vacuumed table table=multipart_uploads20022026/10/01 09:34:04 OK 20260905000000_add_claims.sql (38.39ms)20032026/10/01 09:34:04 INFO Vacuumed table table=closures20042026/10/01 09:34:04 INFO Vacuumed table table=objects20052026/10/01 09:34:04 OK 20260920000000_drop_claims.sql (2.12ms)20062026/10/01 09:34:04 OK 20260923120000_add_pushes.sql (1.63ms)20072026/10/01 09:34:04 goose: successfully migrated database to version: 2026092312000020082026/10/01 09:34:04 OK 1_commit_pending_closure.sql (1.49ms)20092026/10/01 09:34:04 OK 2_object_stats_trigger.sql (544.71µs)20102026/10/01 09:34:04 OK 3_commit_push.sql (276.54µs)20112026/10/01 09:34:04 goose: up to current file version: 320122026-10-01 09:34:04.937 UTC [41415] ERROR: relation "goose_db_version" does not exist at character 3620132026-10-01 09:34:04.937 UTC [41415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2014=== NAME TestClientCADerivations2015 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-41057-1805751233/TestClientCADerivations1806064441/001/store/dxhdzq69h7k8q2gvs8m5djy0g5drkzi4-ca-test2016 client_ca_test.go:139: Found 1 dependencies (including self)20172026/10/01 09:34:05 OK 20241026095416_initial_model.sql (90.55ms)20182026/10/01 09:34:05 OK 20251210153512_drop_unused_gin_index.sql (5.58ms)20192026/10/01 09:34:05 OK 20251218171726_add_pins.sql (15.73ms)20202026/10/01 09:34:05 OK 20260628120000_add_object_size_and_stats.sql (28.75ms)20212026/10/01 09:34:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20222026/10/01 09:34:05 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2023--- PASS: TestCompleteMultipartUnregistered (1.93s)2024=== CONT TestService_RequireScope_OIDC20252026/10/01 09:34:05 OK 20260905000000_add_claims.sql (48.52ms)20262026/10/01 09:34:05 OK 20260920000000_drop_claims.sql (31.19ms)20272026/10/01 09:34:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49237/oidc20282026/10/01 09:34:05 INFO Received push request method=POST path=/api/pushes20292026/10/01 09:34:05 OK 20260923120000_add_pushes.sql (8.3ms)20302026/10/01 09:34:05 goose: successfully migrated database to version: 2026092312000020312026/10/01 09:34:05 OK 1_commit_pending_closure.sql (1.78ms)20322026/10/01 09:34:05 OK 2_object_stats_trigger.sql (515.88µs)20332026/10/01 09:34:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20342026/10/01 09:34:05 INFO Uploading dxhdzq69h7k8q2gvs8m5djy0g5drkzi4-ca-test (144B)20352026/10/01 09:34:05 OK 3_commit_push.sql (416.5µs)20362026/10/01 09:34:05 goose: up to current file version: 320372026-10-01 09:34:05.224 UTC [41426] ERROR: relation "goose_db_version" does not exist at character 3620382026-10-01 09:34:05.224 UTC [41426] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20392026/10/01 09:34:05 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20402026/10/01 09:34:05 WARN Failed to register uploaded object key=dxhdzq69h7k8q2gvs8m5djy0g5drkzi4.ls error="server returned 404: 404 page not found\n"20412026/10/01 09:34:05 WARN Failed to register uploaded object key=log/cqfyxhdp5cjr50v2q056409kb7gr6pb4-ca-test.drv error="server returned 404: 404 page not found\n"20422026/10/01 09:34:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20432026/10/01 09:34:05 INFO Signed narinfos id=1 count=120442026/10/01 09:34:05 INFO Uploading 1 narinfos20452026/10/01 09:34:05 INFO Received complete push request method=POST path=/api/pushes/1/complete20462026/10/01 09:34:05 WARN Failed to register uploaded object key=dxhdzq69h7k8q2gvs8m5djy0g5drkzi4.narinfo error="server returned 404: 404 page not found\n"20472026/10/01 09:34:05 INFO Upload complete. (178ms)2048=== NAME TestClientCADerivations2049 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-41057-1805751233/TestClientCADerivations1806064441/001/store/dxhdzq69h7k8q2gvs8m5djy0g5drkzi4-ca-test2050 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2051 Compression: zstd2052 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2053 NarSize: 1442054 References: 2055 Deriver: /nix/var/nix/builds/nix-41057-1805751233/TestClientCADerivations1806064441/001/store/cqfyxhdp5cjr50v2q056409kb7gr6pb4-ca-test.drv2056 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2057 client_ca_test.go:185: Checking for realisation files in S3...2058 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2059 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2060 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket46?endpoint=http://localhost:65368®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-41057-1805751233/TestClientCADerivations1806064441/001/store'2061 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120622026/10/01 09:34:05 OK 20241026095416_initial_model.sql (118.5ms)20632026/10/01 09:34:05 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)2064--- PASS: TestClientCADerivations (3.88s)2065=== CONT TestGCTaskStore_ConflictDifferentParams2066--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)2067=== CONT TestService_healthCheckHandler20682026/10/01 09:34:05 OK 20251218171726_add_pins.sql (34.22ms)20692026/10/01 09:34:05 INFO Received uploads request method=POST path=/api/pending_closures20702026/10/01 09:34:05 OK 20260628120000_add_object_size_and_stats.sql (27.77ms)20712026/10/01 09:34:05 OK 20260905000000_add_claims.sql (54.39ms)20722026/10/01 09:34:05 OK 20260920000000_drop_claims.sql (2.07ms)20732026/10/01 09:34:05 OK 20260923120000_add_pushes.sql (830.54µs)20742026/10/01 09:34:05 goose: successfully migrated database to version: 2026092312000020752026/10/01 09:34:05 OK 1_commit_pending_closure.sql (1.83ms)20762026/10/01 09:34:05 OK 2_object_stats_trigger.sql (363.67µs)20772026/10/01 09:34:05 OK 3_commit_push.sql (327.71µs)20782026/10/01 09:34:05 goose: up to current file version: 320792026-10-01 09:34:05.534 UTC [41431] ERROR: relation "goose_db_version" does not exist at character 3620802026-10-01 09:34:05.534 UTC [41431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20812026/10/01 09:34:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020822026/10/01 09:34:05 INFO Received create pin request method=POST path=/api/pins/myapp20832026/10/01 09:34:05 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-41057-1805751233/TestPinProtectsFromGC1568531407/001/store/n0ahbw7d65wxqpznidwhbsgww8zy04hy-pinned-file.txt narinfo_key=n0ahbw7d65wxqpznidwhbsgww8zy04hy.narinfo20842026/10/01 09:34:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures20852026/10/01 09:34:05 INFO Garbage collection started20862026/10/01 09:34:05 INFO Aborted multipart uploads count=020872026/10/01 09:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period20882026/10/01 09:34:05 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=020892026/10/01 09:34:05 INFO Vacuumed table table=pending_closures20902026/10/01 09:34:05 INFO Vacuumed table table=pending_objects20912026/10/01 09:34:05 INFO Vacuumed table table=multipart_uploads20922026/10/01 09:34:05 INFO Vacuumed table table=closures20932026/10/01 09:34:05 INFO Vacuumed table table=objects20942026/10/01 09:34:05 OK 20241026095416_initial_model.sql (191.88ms)20952026/10/01 09:34:05 OK 20251210153512_drop_unused_gin_index.sql (18.53ms)20962026/10/01 09:34:05 OK 20251218171726_add_pins.sql (22.76ms)20972026/10/01 09:34:05 INFO Received cleanup request method=DELETE path=/api/pending_closures20982026/10/01 09:34:05 INFO Aborted multipart uploads count=020992026/10/01 09:34:05 INFO Received uploads request method=POST path=/api/pending_closures21002026/10/01 09:34:05 OK 20260628120000_add_object_size_and_stats.sql (46.56ms)21012026/10/01 09:34:05 INFO Received cleanup request method=DELETE path=/api/pending_closures21022026/10/01 09:34:05 INFO Aborted multipart uploads count=121032026/10/01 09:34:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21042026-10-01 09:34:05.923 UTC [41426] ERROR: Closure does not exist: id=121052026-10-01 09:34:05.923 UTC [41426] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE21062026-10-01 09:34:05.923 UTC [41426] STATEMENT: -- name: CommitPendingClosure :exec2107 SELECT commit_pending_closure($1::bigint)2108 2109--- PASS: TestService_cleanupPendingClosuresHandler (2.01s)2110=== CONT TestGracefulShutdownDrainsInflight21112026/10/01 09:34:05 INFO Starting HTTP server address=127.0.0.1:4925621122026/10/01 09:34:05 INFO Shutdown signal received, draining in-flight requests timeout=10s21132026/10/01 09:34:05 OK 20260905000000_add_claims.sql (100.56ms)21142026/10/01 09:34:05 OK 20260920000000_drop_claims.sql (21.64ms)21152026/10/01 09:34:05 OK 20260923120000_add_pushes.sql (10.74ms)21162026/10/01 09:34:05 goose: successfully migrated database to version: 2026092312000021172026/10/01 09:34:05 OK 1_commit_pending_closure.sql (4.51ms)21182026/10/01 09:34:05 OK 2_object_stats_trigger.sql (784.88µs)21192026/10/01 09:34:05 OK 3_commit_push.sql (566.5µs)21202026/10/01 09:34:05 goose: up to current file version: 32121--- PASS: TestGracefulShutdownDrainsInflight (0.07s)2122=== CONT TestGCTaskStore_Fail2123--- PASS: TestGCTaskStore_Fail (0.00s)2124=== CONT TestGCTaskStore_PhaseUpdates2125--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)2126=== CONT TestGCTaskStore_CompletedAllowsNewTask2127--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)2128=== CONT TestGCTaskStore_GetReturnsLatest2129--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)2130=== CONT TestGCTaskStore_GetEmpty2131--- PASS: TestGCTaskStore_GetEmpty (0.00s)2132=== CONT TestCommitRacingPendingCleanupKeepsObjects21332026/10/01 09:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21342026/10/01 09:34:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWJlNGYwYTYtZjc4My00ZTBiLTk2NTMtNjhiZWE3Zjk5MjBmLmMyZTY4ZWU2LWFiOGUtNGE4NS04NzQwLTE0OWRiYmY1ZTRiYXgxNzkwODQ3MjQ0ODkxMjUwMDAw parts=1021352026/10/01 09:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21362026-10-01 09:34:06.165 UTC [41434] ERROR: relation "goose_db_version" does not exist at character 3621372026-10-01 09:34:06.165 UTC [41434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21382026/10/01 09:34:06 INFO Completed upload id=121392026/10/01 09:34:06 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000021402026/10/01 09:34:06 INFO Received uploads request method=POST path=/api/pending_closures21412026/10/01 09:34:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures21422026/10/01 09:34:06 INFO Aborted multipart uploads count=021432026/10/01 09:34:06 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=021442026/10/01 09:34:06 INFO Vacuumed table table=pending_closures2145=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2146=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2147=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2148=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2149=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2150=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2151=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2152=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2153=== CONT TestGCTaskStore_DeduplicateSameParams2154--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)2155=== CONT TestGCTaskStore_StartNew2156--- PASS: TestGCTaskStore_StartNew (0.00s)2157=== CONT TestGCEndsOnShutdown21582026/10/01 09:34:06 INFO Vacuumed table table=pending_objects21592026/10/01 09:34:06 INFO Vacuumed table table=multipart_uploads21602026/10/01 09:34:06 INFO Vacuumed table table=closures21612026/10/01 09:34:06 INFO Vacuumed table table=objects21622026/10/01 09:34:06 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002163--- PASS: TestService_createPendingClosureHandler (3.69s)2164=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21652026/10/01 09:34:06 OK 20241026095416_initial_model.sql (80.49ms)21662026/10/01 09:34:06 OK 20251210153512_drop_unused_gin_index.sql (886.33µs)21672026/10/01 09:34:06 OK 20251218171726_add_pins.sql (1.71ms)21682026/10/01 09:34:06 OK 20260628120000_add_object_size_and_stats.sql (2.66ms)21692026/10/01 09:34:06 OK 20260905000000_add_claims.sql (8.29ms)21702026/10/01 09:34:06 OK 20260920000000_drop_claims.sql (23.53ms)21712026/10/01 09:34:06 OK 20260923120000_add_pushes.sql (5.43ms)21722026/10/01 09:34:06 goose: successfully migrated database to version: 2026092312000021732026/10/01 09:34:06 OK 1_commit_pending_closure.sql (1.51ms)21742026/10/01 09:34:06 OK 2_object_stats_trigger.sql (316.38µs)21752026/10/01 09:34:06 OK 3_commit_push.sql (286.5µs)21762026/10/01 09:34:06 goose: up to current file version: 32177--- PASS: TestService_ReadScope_PublicByDefault (1.80s)2178=== CONT TestService_ReadAuthMiddleware21792026-10-01 09:34:06.634 UTC [41442] ERROR: relation "goose_db_version" does not exist at character 3621802026-10-01 09:34:06.634 UTC [41442] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21812026/10/01 09:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21822026/10/01 09:34:06 OK 20241026095416_initial_model.sql (84.6ms)21832026/10/01 09:34:06 OK 20251210153512_drop_unused_gin_index.sql (4.91ms)21842026/10/01 09:34:06 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWJlNGYwYTYtZjc4My00ZTBiLTk2NTMtNjhiZWE3Zjk5MjBmLjg0NTZkZWIxLTMxMzItNDJmMi05NWE4LWY5OWMwNGIwYzc2NXgxNzkwODQ3MjQ1NDgzMTMwMDAw parts=1021852026/10/01 09:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21862026/10/01 09:34:06 INFO Completed upload id=121872026/10/01 09:34:06 INFO Received uploads request method=POST path=/api/pending_closures21882026/10/01 09:34:06 OK 20251218171726_add_pins.sql (16.37ms)21892026/10/01 09:34:06 INFO Received uploads request method=POST path=/api/pending_closures21902026/10/01 09:34:06 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo21912026/10/01 09:34:06 WARN Found objects in DB but missing from S3, will re-upload count=12192--- PASS: TestService_verifyS3Integrity (3.05s)2193=== CONT TestService_AuthMiddleware_MTLSProxyHeader21942026/10/01 09:34:06 OK 20260628120000_add_object_size_and_stats.sql (17.31ms)21952026-10-01 09:34:06.820 UTC [41444] ERROR: relation "goose_db_version" does not exist at character 3621962026-10-01 09:34:06.820 UTC [41444] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21972026/10/01 09:34:06 OK 20260905000000_add_claims.sql (6.46ms)21982026/10/01 09:34:06 OK 20260920000000_drop_claims.sql (3.74ms)21992026/10/01 09:34:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022002026/10/01 09:34:06 OK 20260923120000_add_pushes.sql (2.6ms)22012026/10/01 09:34:06 goose: successfully migrated database to version: 202609231200002202=== NAME TestClientIntegration2203 client_integration_test.go:323: Objects in database after GC:2204 client_integration_test.go:323: Successfully deleted all objects with GC --force22052026/10/01 09:34:06 OK 1_commit_pending_closure.sql (2.6ms)22062026/10/01 09:34:06 OK 2_object_stats_trigger.sql (2.67ms)22072026/10/01 09:34:06 OK 3_commit_push.sql (513.67µs)22082026/10/01 09:34:06 goose: up to current file version: 32209--- PASS: TestClientIntegration (5.77s)2210=== CONT TestReadProxyRangeRequest2211=== NAME TestOrphanedObjectsGCStressTest2212 orphaned_objects_gc_test.go:509: Stress test completed successfully:2213 orphaned_objects_gc_test.go:510: - Active objects preserved: 202214 orphaned_objects_gc_test.go:511: - Objects deleted: 2102215 orphaned_objects_gc_test.go:512: - Total GC'd: 2102216--- PASS: TestOrphanedObjectsGCStressTest (9.94s)2217=== CONT TestRedundantMultipartUpload22182026/10/01 09:34:06 OK 20241026095416_initial_model.sql (95.49ms)22192026/10/01 09:34:06 OK 20251210153512_drop_unused_gin_index.sql (7ms)22202026/10/01 09:34:06 OK 20251218171726_add_pins.sql (8.33ms)22212026/10/01 09:34:06 OK 20260628120000_add_object_size_and_stats.sql (11.9ms)22222026/10/01 09:34:06 OK 20260905000000_add_claims.sql (30.98ms)22232026/10/01 09:34:07 OK 20260920000000_drop_claims.sql (23.52ms)22242026/10/01 09:34:07 OK 20260923120000_add_pushes.sql (13.23ms)22252026/10/01 09:34:07 goose: successfully migrated database to version: 2026092312000022262026/10/01 09:34:07 OK 1_commit_pending_closure.sql (2.21ms)22272026/10/01 09:34:07 OK 2_object_stats_trigger.sql (336.17µs)22282026/10/01 09:34:07 OK 3_commit_push.sql (301.54µs)22292026/10/01 09:34:07 goose: up to current file version: 32230=== RUN TestService_RequireScope_OIDC/builder_may_write2231=== PAUSE TestService_RequireScope_OIDC/builder_may_write2232=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2233=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2234=== RUN TestService_RequireScope_OIDC/ops_may_admin2235=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2236=== RUN TestService_RequireScope_OIDC/ops_may_not_write2237=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2238=== RUN TestService_RequireScope_OIDC/reader_may_not_write2239=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2240=== RUN TestService_RequireScope_OIDC/static_token_may_admin2241=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2242=== RUN TestService_RequireScope_OIDC/static_token_may_write2243=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2244=== RUN TestService_RequireScope_OIDC/reader_may_read2245=== PAUSE TestService_RequireScope_OIDC/reader_may_read2246=== RUN TestService_RequireScope_OIDC/writer_implies_read2247=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2248=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2249=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2250=== CONT TestPush_SignsNarinfosOfItsPendingObjects2251--- PASS: TestService_healthCheckHandler (1.80s)2252=== CONT TestPush_RejectsBadRequests22532026-10-01 09:34:07.351 UTC [41454] ERROR: relation "goose_db_version" does not exist at character 3622542026-10-01 09:34:07.351 UTC [41454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22552026-10-01 09:34:07.405 UTC [41455] ERROR: relation "goose_db_version" does not exist at character 3622562026-10-01 09:34:07.405 UTC [41455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22572026-10-01 09:34:07.420 UTC [41456] ERROR: relation "goose_db_version" does not exist at character 3622582026-10-01 09:34:07.420 UTC [41456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22592026/10/01 09:34:07 OK 20241026095416_initial_model.sql (38.6ms)22602026/10/01 09:34:07 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)22612026/10/01 09:34:07 OK 20251218171726_add_pins.sql (2.8ms)22622026/10/01 09:34:07 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)22632026/10/01 09:34:07 OK 20260905000000_add_claims.sql (48.53ms)22642026/10/01 09:34:07 OK 20241026095416_initial_model.sql (60.68ms)22652026/10/01 09:34:07 OK 20251210153512_drop_unused_gin_index.sql (11.93ms)22662026/10/01 09:34:07 OK 20260920000000_drop_claims.sql (21.33ms)22672026/10/01 09:34:07 OK 20251218171726_add_pins.sql (12.15ms)22682026/10/01 09:34:07 OK 20260923120000_add_pushes.sql (10.03ms)22692026/10/01 09:34:07 goose: successfully migrated database to version: 2026092312000022702026/10/01 09:34:07 OK 1_commit_pending_closure.sql (2.9ms)22712026/10/01 09:34:07 OK 2_object_stats_trigger.sql (530.17µs)22722026/10/01 09:34:07 OK 3_commit_push.sql (338.96µs)22732026/10/01 09:34:07 goose: up to current file version: 322742026/10/01 09:34:07 OK 20241026095416_initial_model.sql (97.07ms)22752026/10/01 09:34:07 OK 20260628120000_add_object_size_and_stats.sql (23.89ms)22762026/10/01 09:34:07 OK 20251210153512_drop_unused_gin_index.sql (8.6ms)22772026/10/01 09:34:07 OK 20251218171726_add_pins.sql (32ms)22782026/10/01 09:34:07 OK 20260905000000_add_claims.sql (74.5ms)22792026/10/01 09:34:07 OK 20260628120000_add_object_size_and_stats.sql (50.11ms)2280=== NAME TestPinProtectsFromGC2281 client_integration_test.go:840: Pin successfully protected closure from garbage collection22822026/10/01 09:34:07 OK 20260920000000_drop_claims.sql (39.94ms)22832026/10/01 09:34:07 OK 20260923120000_add_pushes.sql (20.72ms)22842026/10/01 09:34:07 goose: successfully migrated database to version: 2026092312000022852026/10/01 09:34:07 OK 1_commit_pending_closure.sql (4.72ms)22862026/10/01 09:34:07 OK 2_object_stats_trigger.sql (843µs)22872026/10/01 09:34:07 OK 3_commit_push.sql (516.13µs)22882026/10/01 09:34:07 goose: up to current file version: 322892026/10/01 09:34:07 OK 20260905000000_add_claims.sql (52.69ms)2290--- PASS: TestPinProtectsFromGC (9.28s)2291=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit22922026/10/01 09:34:07 OK 20260920000000_drop_claims.sql (16.04ms)22932026/10/01 09:34:07 OK 20260923120000_add_pushes.sql (14.16ms)22942026/10/01 09:34:07 goose: successfully migrated database to version: 2026092312000022952026/10/01 09:34:07 OK 1_commit_pending_closure.sql (2.56ms)22962026/10/01 09:34:07 OK 2_object_stats_trigger.sql (833.96µs)22972026/10/01 09:34:07 OK 3_commit_push.sql (545.42µs)22982026/10/01 09:34:07 goose: up to current file version: 322992026/10/01 09:34:07 INFO Aborted multipart uploads count=023002026/10/01 09:34:07 WARN Force mode enabled - objects will be deleted immediately without grace period23012026/10/01 09:34:07 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=023022026/10/01 09:34:07 INFO Vacuumed table table=pending_closures23032026/10/01 09:34:07 INFO Vacuumed table table=pending_objects23042026/10/01 09:34:07 INFO Vacuumed table table=multipart_uploads23052026/10/01 09:34:07 INFO Vacuumed table table=closures23062026/10/01 09:34:07 INFO Vacuumed table table=objects2307--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.97s)2308=== CONT TestPush_CompleteCommitsEveryRoot23092026-10-01 09:34:08.038 UTC [41463] ERROR: relation "goose_db_version" does not exist at character 3623102026-10-01 09:34:08.038 UTC [41463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2311--- PASS: TestGCEndsOnShutdown (1.88s)2312=== CONT TestPush_OverlappingRootsStoreOneRowPerKey23132026/10/01 09:34:08 OK 20241026095416_initial_model.sql (251.2ms)23142026/10/01 09:34:08 OK 20251210153512_drop_unused_gin_index.sql (10.67ms)23152026/10/01 09:34:08 OK 20251218171726_add_pins.sql (59.61ms)23162026/10/01 09:34:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"23172026/10/01 09:34:08 WARN mTLS auth: bound subjects configured but subject DN unavailable23182026/10/01 09:34:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2319--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.15s)2320=== CONT TestReadRedirectUsesPublicS3URL23212026/10/01 09:34:08 OK 20260628120000_add_object_size_and_stats.sql (20.95ms)23222026/10/01 09:34:08 OK 20260905000000_add_claims.sql (58.69ms)23232026/10/01 09:34:08 OK 20260920000000_drop_claims.sql (21.52ms)23242026/10/01 09:34:08 OK 20260923120000_add_pushes.sql (32.42ms)23252026/10/01 09:34:08 goose: successfully migrated database to version: 2026092312000023262026/10/01 09:34:08 OK 1_commit_pending_closure.sql (5.75ms)23272026/10/01 09:34:08 OK 2_object_stats_trigger.sql (567.46µs)23282026/10/01 09:34:08 OK 3_commit_push.sql (515.63µs)23292026/10/01 09:34:08 goose: up to current file version: 323302026-10-01 09:34:08.656 UTC [41470] ERROR: relation "goose_db_version" does not exist at character 3623312026-10-01 09:34:08.656 UTC [41470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23322026-10-01 09:34:08.663 UTC [41469] ERROR: relation "goose_db_version" does not exist at character 3623332026-10-01 09:34:08.663 UTC [41469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23342026-10-01 09:34:08.669 UTC [41471] ERROR: relation "goose_db_version" does not exist at character 3623352026-10-01 09:34:08.669 UTC [41471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23362026/10/01 09:34:08 OK 20241026095416_initial_model.sql (176.97ms)23372026/10/01 09:34:08 OK 20241026095416_initial_model.sql (178.04ms)23382026/10/01 09:34:08 OK 20241026095416_initial_model.sql (194.86ms)23392026/10/01 09:34:08 OK 20251210153512_drop_unused_gin_index.sql (17.68ms)23402026/10/01 09:34:08 OK 20251210153512_drop_unused_gin_index.sql (16.86ms)2341--- PASS: TestService_ReadAuthMiddleware (2.37s)2342=== CONT TestSweepRechecksPendingAfterLocking23432026/10/01 09:34:08 OK 20251210153512_drop_unused_gin_index.sql (15.9ms)23442026/10/01 09:34:08 OK 20251218171726_add_pins.sql (34.16ms)23452026/10/01 09:34:08 OK 20251218171726_add_pins.sql (34.3ms)23462026/10/01 09:34:08 OK 20251218171726_add_pins.sql (24.97ms)23472026-10-01 09:34:08.976 UTC [41472] ERROR: relation "goose_db_version" does not exist at character 3623482026-10-01 09:34:08.976 UTC [41472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23492026/10/01 09:34:08 OK 20260628120000_add_object_size_and_stats.sql (20.82ms)23502026/10/01 09:34:08 OK 20260628120000_add_object_size_and_stats.sql (29.27ms)23512026/10/01 09:34:08 OK 20260628120000_add_object_size_and_stats.sql (29.44ms)23522026/10/01 09:34:09 OK 20260905000000_add_claims.sql (20.07ms)23532026/10/01 09:34:09 OK 20260905000000_add_claims.sql (18.66ms)23542026/10/01 09:34:09 OK 20260905000000_add_claims.sql (18.63ms)23552026/10/01 09:34:09 OK 20260920000000_drop_claims.sql (2.63ms)23562026/10/01 09:34:09 OK 20260920000000_drop_claims.sql (2.6ms)23572026/10/01 09:34:09 OK 20260920000000_drop_claims.sql (2.68ms)23582026/10/01 09:34:09 OK 20260923120000_add_pushes.sql (4.68ms)23592026/10/01 09:34:09 goose: successfully migrated database to version: 2026092312000023602026/10/01 09:34:09 OK 20260923120000_add_pushes.sql (4.8ms)23612026/10/01 09:34:09 goose: successfully migrated database to version: 2026092312000023622026/10/01 09:34:09 OK 20260923120000_add_pushes.sql (4.88ms)23632026/10/01 09:34:09 goose: successfully migrated database to version: 2026092312000023642026/10/01 09:34:09 OK 1_commit_pending_closure.sql (3.51ms)23652026/10/01 09:34:09 OK 1_commit_pending_closure.sql (3.72ms)23662026/10/01 09:34:09 OK 1_commit_pending_closure.sql (3.67ms)23672026/10/01 09:34:09 OK 2_object_stats_trigger.sql (703.29µs)23682026/10/01 09:34:09 OK 2_object_stats_trigger.sql (497.58µs)23692026/10/01 09:34:09 OK 2_object_stats_trigger.sql (479.04µs)23702026/10/01 09:34:09 OK 3_commit_push.sql (316.04µs)23712026/10/01 09:34:09 goose: up to current file version: 323722026/10/01 09:34:09 OK 3_commit_push.sql (358.92µs)23732026/10/01 09:34:09 goose: up to current file version: 323742026/10/01 09:34:09 OK 3_commit_push.sql (393.5µs)23752026/10/01 09:34:09 goose: up to current file version: 323762026-10-01 09:34:09.067 UTC [41475] ERROR: relation "goose_db_version" does not exist at character 3623772026-10-01 09:34:09.067 UTC [41475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23782026/10/01 09:34:09 OK 20241026095416_initial_model.sql (88.46ms)23792026/10/01 09:34:09 OK 20251210153512_drop_unused_gin_index.sql (19.49ms)23802026/10/01 09:34:09 OK 20251218171726_add_pins.sql (15.67ms)23812026/10/01 09:34:09 OK 20260628120000_add_object_size_and_stats.sql (35.81ms)23822026/10/01 09:34:09 OK 20260905000000_add_claims.sql (64.43ms)23832026/10/01 09:34:09 OK 20260920000000_drop_claims.sql (45.25ms)23842026/10/01 09:34:09 OK 20241026095416_initial_model.sql (169.93ms)23852026/10/01 09:34:09 OK 20251210153512_drop_unused_gin_index.sql (15.15ms)23862026/10/01 09:34:09 OK 20260923120000_add_pushes.sql (26.42ms)23872026/10/01 09:34:09 goose: successfully migrated database to version: 2026092312000023882026/10/01 09:34:09 OK 1_commit_pending_closure.sql (4.28ms)23892026/10/01 09:34:09 OK 2_object_stats_trigger.sql (2.84ms)23902026/10/01 09:34:09 OK 3_commit_push.sql (1.95ms)23912026/10/01 09:34:09 goose: up to current file version: 323922026/10/01 09:34:09 OK 20251218171726_add_pins.sql (34.92ms)2393--- PASS: TestReadProxyRangeRequest (2.53s)2394=== CONT TestPushWaitsForSweepHoldingRow23952026/10/01 09:34:09 OK 20260628120000_add_object_size_and_stats.sql (47.53ms)23962026/10/01 09:34:09 OK 20260905000000_add_claims.sql (74.64ms)23972026/10/01 09:34:09 OK 20260920000000_drop_claims.sql (34.6ms)23982026/10/01 09:34:09 OK 20260923120000_add_pushes.sql (18.31ms)23992026/10/01 09:34:09 goose: successfully migrated database to version: 2026092312000024002026/10/01 09:34:09 OK 1_commit_pending_closure.sql (3.82ms)24012026/10/01 09:34:09 OK 2_object_stats_trigger.sql (729.88µs)24022026/10/01 09:34:09 OK 3_commit_push.sql (481.08µs)24032026/10/01 09:34:09 goose: up to current file version: 32404--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.80s)2405=== CONT TestReadProxyRootRedirectsToIndexHTML24062026-10-01 09:34:09.819 UTC [41480] ERROR: relation "goose_db_version" does not exist at character 3624072026-10-01 09:34:09.819 UTC [41480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24082026/10/01 09:34:09 INFO Received uploads request method=POST path=/api/pending_closures24092026/10/01 09:34:10 INFO Received uploads request method=POST path=/api/pending_closures24102026/10/01 09:34:10 OK 20241026095416_initial_model.sql (281.82ms)24112026/10/01 09:34:10 OK 20251210153512_drop_unused_gin_index.sql (12.84ms)24122026/10/01 09:34:10 OK 20251218171726_add_pins.sql (56.71ms)24132026/10/01 09:34:10 OK 20260628120000_add_object_size_and_stats.sql (47.86ms)24142026/10/01 09:34:10 INFO Received push request method=POST path=/api/pushes24152026/10/01 09:34:10 OK 20260905000000_add_claims.sql (102.56ms)24162026/10/01 09:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24172026/10/01 09:34:10 INFO Signed narinfos id=1 count=12418--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.44s)2419=== CONT TestReadRedirectKeepsNarinfoProxied24202026/10/01 09:34:10 OK 20260920000000_drop_claims.sql (98.63ms)24212026-10-01 09:34:10.497 UTC [41481] ERROR: relation "goose_db_version" does not exist at character 3624222026-10-01 09:34:10.497 UTC [41481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24232026/10/01 09:34:10 OK 20260923120000_add_pushes.sql (5.79ms)24242026/10/01 09:34:10 goose: successfully migrated database to version: 2026092312000024252026-10-01 09:34:10.499 UTC [41482] ERROR: relation "goose_db_version" does not exist at character 3624262026-10-01 09:34:10.499 UTC [41482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24272026/10/01 09:34:10 OK 1_commit_pending_closure.sql (3ms)24282026/10/01 09:34:10 OK 2_object_stats_trigger.sql (442.08µs)24292026/10/01 09:34:10 OK 3_commit_push.sql (342.13µs)24302026/10/01 09:34:10 goose: up to current file version: 32431=== RUN TestPush_RejectsBadRequests/no_roots2432=== PAUSE TestPush_RejectsBadRequests/no_roots2433=== RUN TestPush_RejectsBadRequests/no_objects2434=== PAUSE TestPush_RejectsBadRequests/no_objects2435=== RUN TestPush_RejectsBadRequests/bad_root2436=== PAUSE TestPush_RejectsBadRequests/bad_root2437=== RUN TestPush_RejectsBadRequests/root_not_in_objects2438=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2439=== CONT TestReadRedirectNar24402026/10/01 09:34:10 OK 20241026095416_initial_model.sql (194.38ms)24412026/10/01 09:34:10 OK 20241026095416_initial_model.sql (195.57ms)24422026/10/01 09:34:10 OK 20251210153512_drop_unused_gin_index.sql (5.96ms)24432026/10/01 09:34:10 OK 20251210153512_drop_unused_gin_index.sql (5.07ms)24442026/10/01 09:34:10 OK 20251218171726_add_pins.sql (16.56ms)24452026/10/01 09:34:10 OK 20251218171726_add_pins.sql (16.58ms)24462026-10-01 09:34:10.836 UTC [41487] ERROR: relation "goose_db_version" does not exist at character 3624472026-10-01 09:34:10.836 UTC [41487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24482026/10/01 09:34:10 OK 20260628120000_add_object_size_and_stats.sql (47.52ms)24492026/10/01 09:34:10 OK 20260628120000_add_object_size_and_stats.sql (47.58ms)24502026/10/01 09:34:10 OK 20260905000000_add_claims.sql (37.13ms)24512026/10/01 09:34:10 OK 20260905000000_add_claims.sql (37.2ms)24522026/10/01 09:34:10 OK 20260920000000_drop_claims.sql (18.3ms)24532026/10/01 09:34:10 OK 20260920000000_drop_claims.sql (22.64ms)24542026/10/01 09:34:10 OK 20260923120000_add_pushes.sql (20.24ms)24552026/10/01 09:34:10 goose: successfully migrated database to version: 2026092312000024562026/10/01 09:34:10 OK 20260923120000_add_pushes.sql (17.63ms)24572026/10/01 09:34:10 goose: successfully migrated database to version: 2026092312000024582026/10/01 09:34:10 OK 1_commit_pending_closure.sql (3.98ms)24592026/10/01 09:34:10 OK 1_commit_pending_closure.sql (2.68ms)24602026/10/01 09:34:10 OK 2_object_stats_trigger.sql (524.79µs)24612026/10/01 09:34:10 OK 2_object_stats_trigger.sql (427.79µs)24622026/10/01 09:34:10 OK 3_commit_push.sql (407.46µs)24632026/10/01 09:34:10 goose: up to current file version: 324642026/10/01 09:34:10 OK 3_commit_push.sql (379.33µs)24652026/10/01 09:34:10 goose: up to current file version: 324662026/10/01 09:34:10 INFO Received push request method=POST path=/api/pushes24672026/10/01 09:34:11 INFO Received complete push request method=POST path=/api/pushes/1/complete24682026/10/01 09:34:11 INFO Received push request method=POST path=/api/pushes24692026/10/01 09:34:11 OK 20241026095416_initial_model.sql (227.96ms)24702026/10/01 09:34:11 OK 20251210153512_drop_unused_gin_index.sql (25ms)24712026/10/01 09:34:11 OK 20251218171726_add_pins.sql (46.54ms)24722026/10/01 09:34:11 INFO Aborted multipart uploads count=024732026/10/01 09:34:11 WARN Force mode enabled - objects will be deleted immediately without grace period24742026/10/01 09:34:11 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=024752026/10/01 09:34:11 OK 20260628120000_add_object_size_and_stats.sql (52.13ms)24762026/10/01 09:34:11 INFO Vacuumed table table=pending_closures24772026/10/01 09:34:11 INFO Vacuumed table table=pending_objects24782026/10/01 09:34:11 INFO Received push request method=POST path=/api/pushes24792026/10/01 09:34:11 INFO Vacuumed table table=multipart_uploads24802026/10/01 09:34:11 OK 20260905000000_add_claims.sql (79.54ms)24812026/10/01 09:34:11 INFO Vacuumed table table=closures24822026/10/01 09:34:11 INFO Vacuumed table table=objects24832026/10/01 09:34:11 INFO Received complete push request method=POST path=/api/pushes/2/complete2484--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.75s)2485=== CONT TestReadProxyDisabled24862026/10/01 09:34:11 OK 20260920000000_drop_claims.sql (112.69ms)24872026-10-01 09:34:11.443 UTC [41489] ERROR: relation "goose_db_version" does not exist at character 3624882026-10-01 09:34:11.443 UTC [41489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24892026/10/01 09:34:11 INFO Received complete push request method=POST path=/api/pushes/1/complete24902026/10/01 09:34:11 OK 20260923120000_add_pushes.sql (21.56ms)24912026/10/01 09:34:11 goose: successfully migrated database to version: 2026092312000024922026/10/01 09:34:11 OK 1_commit_pending_closure.sql (2.28ms)24932026/10/01 09:34:11 OK 2_object_stats_trigger.sql (398.96µs)24942026/10/01 09:34:11 OK 3_commit_push.sql (320.71µs)24952026/10/01 09:34:11 goose: up to current file version: 32496--- PASS: TestPush_CompleteCommitsEveryRoot (3.52s)2497=== CONT TestReadProxyHead24982026/10/01 09:34:11 INFO Received push request method=POST path=/api/pushes2499--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.68s)2500=== CONT TestReadProxyConditionalGet25012026/10/01 09:34:11 OK 20241026095416_initial_model.sql (295.59ms)25022026/10/01 09:34:11 OK 20251210153512_drop_unused_gin_index.sql (13.44ms)25032026/10/01 09:34:11 OK 20251218171726_add_pins.sql (25.88ms)25042026/10/01 09:34:12 OK 20260628120000_add_object_size_and_stats.sql (54.13ms)25052026/10/01 09:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25062026/10/01 09:34:12 OK 20260905000000_add_claims.sql (94.81ms)2507--- PASS: TestReadRedirectUsesPublicS3URL (3.69s)2508=== CONT TestGetExistingObjectsLocksRows25092026/10/01 09:34:12 OK 20260920000000_drop_claims.sql (61.12ms)25102026/10/01 09:34:12 OK 20260923120000_add_pushes.sql (22.05ms)25112026/10/01 09:34:12 goose: successfully migrated database to version: 2026092312000025122026/10/01 09:34:12 OK 1_commit_pending_closure.sql (2.84ms)25132026/10/01 09:34:12 OK 2_object_stats_trigger.sql (531.63µs)25142026/10/01 09:34:12 OK 3_commit_push.sql (450.42µs)25152026/10/01 09:34:12 goose: up to current file version: 325162026/10/01 09:34:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWJlNGYwYTYtZjc4My00ZTBiLTk2NTMtNjhiZWE3Zjk5MjBmLjU4ZGIxNjFhLTA2MjUtNDgwZi04ZWUzLTk3OTA3N2RkNWRjNHgxNzkwODQ3MjQ5OTc4MjAwMDAw parts=122517--- PASS: TestRedundantMultipartUpload (5.35s)2518=== CONT TestRegisterCompletedObjectNeedsPendingRow25192026-10-01 09:34:12.247 UTC [41499] ERROR: relation "goose_db_version" does not exist at character 3625202026-10-01 09:34:12.247 UTC [41499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25212026/10/01 09:34:12 OK 20241026095416_initial_model.sql (251.52ms)25222026/10/01 09:34:12 INFO Aborted multipart uploads count=025232026/10/01 09:34:12 OK 20251210153512_drop_unused_gin_index.sql (16.59ms)25242026/10/01 09:34:12 WARN Force mode enabled - objects will be deleted immediately without grace period25252026-10-01 09:34:12.598 UTC [41503] ERROR: relation "goose_db_version" does not exist at character 3625262026-10-01 09:34:12.598 UTC [41503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25272026/10/01 09:34:12 OK 20251218171726_add_pins.sql (23.45ms)25282026/10/01 09:34:12 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=025292026/10/01 09:34:12 INFO Vacuumed table table=pending_closures25302026/10/01 09:34:12 OK 20260628120000_add_object_size_and_stats.sql (49.41ms)25312026/10/01 09:34:12 INFO Vacuumed table table=pending_objects25322026/10/01 09:34:12 INFO Vacuumed table table=multipart_uploads25332026/10/01 09:34:12 INFO Vacuumed table table=closures25342026/10/01 09:34:12 INFO Vacuumed table table=objects25352026/10/01 09:34:12 OK 20260905000000_add_claims.sql (20.17ms)2536--- PASS: TestSweepRechecksPendingAfterLocking (3.74s)2537=== CONT TestReadProxyInvalidPath25382026/10/01 09:34:12 OK 20260920000000_drop_claims.sql (6.95ms)25392026-10-01 09:34:12.685 UTC [41507] ERROR: relation "goose_db_version" does not exist at character 3625402026-10-01 09:34:12.685 UTC [41507] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25412026/10/01 09:34:12 OK 20260923120000_add_pushes.sql (9.95ms)25422026/10/01 09:34:12 goose: successfully migrated database to version: 2026092312000025432026/10/01 09:34:12 OK 1_commit_pending_closure.sql (2.03ms)25442026/10/01 09:34:12 OK 2_object_stats_trigger.sql (475.83µs)25452026/10/01 09:34:12 OK 3_commit_push.sql (403.58µs)25462026/10/01 09:34:12 goose: up to current file version: 325472026-10-01 09:34:12.786 UTC [41508] ERROR: relation "goose_db_version" does not exist at character 3625482026-10-01 09:34:12.786 UTC [41508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25492026/10/01 09:34:12 OK 20241026095416_initial_model.sql (187.23ms)25502026/10/01 09:34:12 OK 20251210153512_drop_unused_gin_index.sql (12.47ms)25512026/10/01 09:34:12 OK 20251218171726_add_pins.sql (32.32ms)25522026/10/01 09:34:12 OK 20260628120000_add_object_size_and_stats.sql (20.64ms)25532026/10/01 09:34:12 OK 20260905000000_add_claims.sql (36.99ms)25542026/10/01 09:34:12 OK 20260920000000_drop_claims.sql (14.73ms)25552026/10/01 09:34:12 OK 20260923120000_add_pushes.sql (26.46ms)25562026/10/01 09:34:12 goose: successfully migrated database to version: 2026092312000025572026/10/01 09:34:12 OK 1_commit_pending_closure.sql (4.74ms)25582026/10/01 09:34:12 OK 2_object_stats_trigger.sql (916.54µs)25592026/10/01 09:34:13 OK 3_commit_push.sql (1.17ms)25602026/10/01 09:34:13 goose: up to current file version: 325612026/10/01 09:34:13 OK 20241026095416_initial_model.sql (141.57ms)25622026/10/01 09:34:13 OK 20241026095416_initial_model.sql (140.22ms)25632026/10/01 09:34:13 OK 20251210153512_drop_unused_gin_index.sql (15.44ms)25642026/10/01 09:34:13 OK 20251210153512_drop_unused_gin_index.sql (15.5ms)25652026/10/01 09:34:13 OK 20251218171726_add_pins.sql (35.83ms)25662026/10/01 09:34:13 OK 20251218171726_add_pins.sql (35.75ms)25672026/10/01 09:34:13 OK 20260628120000_add_object_size_and_stats.sql (16.12ms)25682026/10/01 09:34:13 OK 20260628120000_add_object_size_and_stats.sql (17.91ms)25692026/10/01 09:34:13 INFO Received uploads request method=POST path=/api/pending_closures25702026/10/01 09:34:13 OK 20260905000000_add_claims.sql (71ms)25712026/10/01 09:34:13 OK 20260905000000_add_claims.sql (69.16ms)25722026/10/01 09:34:13 OK 20260920000000_drop_claims.sql (42.92ms)25732026/10/01 09:34:13 OK 20260920000000_drop_claims.sql (46.34ms)25742026/10/01 09:34:13 OK 20260923120000_add_pushes.sql (17ms)25752026/10/01 09:34:13 goose: successfully migrated database to version: 2026092312000025762026/10/01 09:34:13 OK 1_commit_pending_closure.sql (4.62ms)25772026/10/01 09:34:13 OK 20260923120000_add_pushes.sql (18.95ms)25782026/10/01 09:34:13 goose: successfully migrated database to version: 2026092312000025792026/10/01 09:34:13 OK 2_object_stats_trigger.sql (1.54ms)25802026/10/01 09:34:13 OK 3_commit_push.sql (927.33µs)25812026/10/01 09:34:13 goose: up to current file version: 325822026/10/01 09:34:13 OK 1_commit_pending_closure.sql (3.71ms)25832026/10/01 09:34:13 OK 2_object_stats_trigger.sql (715.75µs)25842026/10/01 09:34:13 OK 3_commit_push.sql (548.58µs)25852026/10/01 09:34:13 goose: up to current file version: 32586--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.74s)2587=== CONT TestReadProxy4042588--- PASS: TestPushWaitsForSweepHoldingRow (4.22s)2589=== CONT TestIsValidUploadKey/narinfo2590=== CONT TestIsValidUploadKey/realisation_plus_in_output2591=== CONT TestIsValidUploadKey/unknown_type2592=== CONT TestIsValidUploadKey/empty_key2593=== CONT TestIsValidUploadKey/absolute2594=== CONT TestIsValidUploadKey/traversal_nar2595=== CONT TestIsValidUploadKey/traversal2596=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2597=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2598=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2599=== CONT TestIsValidUploadKey/index.html2600=== CONT TestIsValidUploadKey/nix-cache-info2601=== CONT TestIsValidUploadKey/build_log_question_mark2602=== CONT TestIsValidUploadKey/realisation2603=== CONT TestIsValidUploadKey/build_log_equals2604=== CONT TestIsValidUploadKey/nar_xz2605=== CONT TestIsValidUploadKey/listing2606=== CONT TestIsValidUploadKey/nar_plain2607=== CONT TestIsValidUploadKey/build_log_plus_in_name2608=== CONT TestIsValidUploadKey/build_log_home-manager_file2609=== CONT TestIsValidUploadKey/nar_zst2610=== CONT TestIsValidUploadKey/build_log2611--- PASS: TestIsValidUploadKey (0.01s)2612 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2613 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2614 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2615 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2616 --- PASS: TestIsValidUploadKey/absolute (0.00s)2617 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2618 --- PASS: TestIsValidUploadKey/traversal (0.00s)2619 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2620 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2621 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2622 --- PASS: TestIsValidUploadKey/index.html (0.00s)2623 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2624 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2625 --- PASS: TestIsValidUploadKey/realisation (0.00s)2626 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2627 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2628 --- PASS: TestIsValidUploadKey/listing (0.00s)2629 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2630 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2631 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2632 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2633 --- PASS: TestIsValidUploadKey/build_log (0.00s)2634=== CONT TestIsValidCachePath/traversal_parent2635=== CONT TestIsValidCachePath/narinfo2636=== CONT TestIsValidCachePath/index.html2637=== CONT TestIsValidCachePath/nix-cache-info2638=== CONT TestIsValidCachePath/realisation2639=== CONT TestIsValidCachePath/log2640=== CONT TestIsValidCachePath/ls2641=== CONT TestIsValidCachePath/nar_uncompressed2642=== CONT TestIsValidCachePath/nar_bz22643=== CONT TestIsValidCachePath/nar_xz2644=== CONT TestIsValidCachePath/nar_zst2645=== CONT TestIsValidCachePath/empty2646=== CONT TestIsValidCachePath/short_hash2647=== CONT TestIsValidCachePath/leading_slash2648=== CONT TestIsValidCachePath/wrong_extension2649=== CONT TestIsValidCachePath/invalid_char_u2650=== CONT TestIsValidCachePath/random_path2651=== CONT TestIsValidCachePath/invalid_char_e2652=== CONT TestIsValidCachePath/traversal_in_middle2653=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2654--- PASS: TestIsValidCachePath (0.01s)2655 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2656 --- PASS: TestIsValidCachePath/narinfo (0.00s)2657 --- PASS: TestIsValidCachePath/index.html (0.00s)2658 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2659 --- PASS: TestIsValidCachePath/realisation (0.00s)2660 --- PASS: TestIsValidCachePath/log (0.00s)2661 --- PASS: TestIsValidCachePath/ls (0.00s)2662 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2663 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2664 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2665 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2666 --- PASS: TestIsValidCachePath/empty (0.00s)2667 --- PASS: TestIsValidCachePath/short_hash (0.00s)2668 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2669 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2670 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2671 --- PASS: TestIsValidCachePath/random_path (0.00s)2672 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2673 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2674 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2675=== CONT TestProxyWriteTimeout/narinfo2676=== CONT TestProxyWriteTimeout/10_GiB_nar2677=== CONT TestProxyWriteTimeout/unknown_size2678=== CONT TestProxyWriteTimeout/1_GiB_nar2679--- PASS: TestProxyWriteTimeout (0.00s)2680 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2681 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2682 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2683 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2684=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows26852026-10-01 09:34:13.645 UTC [41513] ERROR: relation "goose_db_version" does not exist at character 3626862026-10-01 09:34:13.645 UTC [41513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2687--- PASS: TestReadRedirectNar (2.96s)2688=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check26892026-10-01 09:34:13.704 UTC [41516] ERROR: relation "goose_db_version" does not exist at character 3626902026-10-01 09:34:13.704 UTC [41516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2691--- PASS: TestReadRedirectKeepsNarinfoProxied (3.50s)2692=== CONT TestResolveDBConnectionString/flag_wins2693=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2694=== CONT TestResolveDBConnectionString/nothing_configured2695=== CONT TestResolveDBConnectionString/missing_file_is_an_error2696=== CONT TestResolveDBConnectionString/file_when_flag_empty2697=== CONT TestParseSingleRange/none2698=== CONT TestParseSingleRange/open-ended2699=== CONT TestParseSingleRange/start_far_past_EOF2700=== CONT TestParseSingleRange/start_past_EOF2701=== CONT TestParseSingleRange/single_byte2702=== CONT TestParseSingleRange/suffix_exceeds_size2703=== CONT TestParseSingleRange/suffix2704--- PASS: TestResolveDBConnectionString (0.01s)2705 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2706 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2707 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2708 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2709 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2710=== CONT TestParseSingleRange/end_clamped_to_size2711=== CONT TestParseSingleRange/malformed_both_empty2712=== CONT TestParseSingleRange/closed2713=== CONT TestParseSingleRange/malformed_end_before_start2714=== CONT TestParseSingleRange/multi-range_ignored2715=== CONT TestParseSingleRange/malformed_no_dash2716=== CONT TestParseSingleRange/unknown_unit2717--- PASS: TestParseSingleRange (0.00s)2718 --- PASS: TestParseSingleRange/none (0.00s)2719 --- PASS: TestParseSingleRange/open-ended (0.00s)2720 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2721 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2722 --- PASS: TestParseSingleRange/single_byte (0.00s)2723 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2724 --- PASS: TestParseSingleRange/suffix (0.00s)2725 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2726 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2727 --- PASS: TestParseSingleRange/closed (0.00s)2728 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2729 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2730 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2731 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2732=== CONT TestServerTLSConfig/no_client_CA2733=== CONT TestServerTLSConfig/not_a_PEM_file27342026/10/01 09:34:13 OK 20241026095416_initial_model.sql (200.17ms)27352026-10-01 09:34:13.976 UTC [41519] ERROR: relation "goose_db_version" does not exist at character 3627362026-10-01 09:34:13.976 UTC [41519] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2737=== CONT TestServerTLSConfig/missing_CA_file2738--- PASS: TestServerTLSConfig (0.00s)2739 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2740 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2741 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2742=== CONT TestClientErrorHandling/InvalidStorePath27432026/10/01 09:34:13 OK 20251210153512_drop_unused_gin_index.sql (10.03ms)27442026/10/01 09:34:13 OK 20241026095416_initial_model.sql (210.95ms)27452026/10/01 09:34:13 OK 20251210153512_drop_unused_gin_index.sql (9.7ms)27462026/10/01 09:34:13 OK 20251218171726_add_pins.sql (11.43ms)27472026/10/01 09:34:14 OK 20251218171726_add_pins.sql (22.5ms)27482026/10/01 09:34:14 OK 20260628120000_add_object_size_and_stats.sql (30.87ms)27492026/10/01 09:34:14 OK 20260628120000_add_object_size_and_stats.sql (20.61ms)27502026-10-01 09:34:14.040 UTC [41522] ERROR: relation "goose_db_version" does not exist at character 3627512026-10-01 09:34:14.040 UTC [41522] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27522026/10/01 09:34:14 OK 20260905000000_add_claims.sql (12.06ms)27532026/10/01 09:34:14 OK 20260920000000_drop_claims.sql (32.96ms)27542026/10/01 09:34:14 OK 20260905000000_add_claims.sql (48.51ms)27552026/10/01 09:34:14 OK 20260923120000_add_pushes.sql (20.27ms)27562026/10/01 09:34:14 goose: successfully migrated database to version: 2026092312000027572026/10/01 09:34:14 OK 20241026095416_initial_model.sql (83.79ms)27582026/10/01 09:34:14 OK 20260920000000_drop_claims.sql (9.3ms)27592026/10/01 09:34:14 OK 1_commit_pending_closure.sql (5.14ms)27602026/10/01 09:34:14 OK 2_object_stats_trigger.sql (648.33µs)27612026/10/01 09:34:14 OK 3_commit_push.sql (434µs)27622026/10/01 09:34:14 goose: up to current file version: 327632026/10/01 09:34:14 OK 20251210153512_drop_unused_gin_index.sql (6.26ms)27642026/10/01 09:34:14 OK 20260923120000_add_pushes.sql (11.85ms)27652026/10/01 09:34:14 goose: successfully migrated database to version: 2026092312000027662026/10/01 09:34:14 OK 1_commit_pending_closure.sql (1.89ms)27672026/10/01 09:34:14 OK 2_object_stats_trigger.sql (369.04µs)27682026/10/01 09:34:14 OK 3_commit_push.sql (345.5µs)27692026/10/01 09:34:14 goose: up to current file version: 327702026/10/01 09:34:14 OK 20251218171726_add_pins.sql (44.8ms)27712026-10-01 09:34:14.155 UTC [41523] ERROR: relation "goose_db_version" does not exist at character 3627722026-10-01 09:34:14.155 UTC [41523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27732026/10/01 09:34:14 OK 20260628120000_add_object_size_and_stats.sql (18.44ms)27742026/10/01 09:34:14 OK 20260905000000_add_claims.sql (59.94ms)27752026/10/01 09:34:14 OK 20241026095416_initial_model.sql (158.03ms)27762026/10/01 09:34:14 OK 20251210153512_drop_unused_gin_index.sql (21.48ms)27772026/10/01 09:34:14 OK 20260920000000_drop_claims.sql (49.28ms)27782026/10/01 09:34:14 OK 20260923120000_add_pushes.sql (29.29ms)27792026/10/01 09:34:14 goose: successfully migrated database to version: 2026092312000027802026/10/01 09:34:14 OK 1_commit_pending_closure.sql (4.85ms)27812026/10/01 09:34:14 OK 2_object_stats_trigger.sql (1.07ms)27822026/10/01 09:34:14 OK 3_commit_push.sql (763.42µs)27832026/10/01 09:34:14 goose: up to current file version: 327842026/10/01 09:34:14 OK 20251218171726_add_pins.sql (47.48ms)27852026/10/01 09:34:14 OK 20260628120000_add_object_size_and_stats.sql (45.24ms)27862026/10/01 09:34:14 OK 20260905000000_add_claims.sql (70.6ms)27872026/10/01 09:34:14 OK 20241026095416_initial_model.sql (231.48ms)27882026/10/01 09:34:14 OK 20251210153512_drop_unused_gin_index.sql (19.83ms)2789--- PASS: TestReadProxyHead (2.99s)2790=== CONT TestClientErrorHandling/ServerNotAvailable27912026/10/01 09:34:14 OK 20260920000000_drop_claims.sql (45.7ms)27922026/10/01 09:34:14 OK 20260923120000_add_pushes.sql (26.48ms)27932026/10/01 09:34:14 goose: successfully migrated database to version: 2026092312000027942026/10/01 09:34:14 OK 20251218171726_add_pins.sql (44.55ms)27952026/10/01 09:34:14 OK 1_commit_pending_closure.sql (3.95ms)27962026/10/01 09:34:14 OK 2_object_stats_trigger.sql (771.38µs)27972026/10/01 09:34:14 OK 3_commit_push.sql (1.33ms)27982026/10/01 09:34:14 goose: up to current file version: 327992026/10/01 09:34:14 OK 20260628120000_add_object_size_and_stats.sql (53.92ms)28002026/10/01 09:34:14 OK 20260905000000_add_claims.sql (59.32ms)28012026/10/01 09:34:14 OK 20260920000000_drop_claims.sql (32.66ms)28022026/10/01 09:34:14 OK 20260923120000_add_pushes.sql (9.39ms)28032026/10/01 09:34:14 goose: successfully migrated database to version: 2026092312000028042026-10-01 09:34:14.666 UTC [41526] ERROR: relation "goose_db_version" does not exist at character 3628052026-10-01 09:34:14.666 UTC [41526] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28062026/10/01 09:34:14 OK 1_commit_pending_closure.sql (1.43ms)28072026/10/01 09:34:14 OK 2_object_stats_trigger.sql (323.75µs)28082026/10/01 09:34:14 OK 3_commit_push.sql (285.71µs)28092026/10/01 09:34:14 goose: up to current file version: 32810--- PASS: TestReadProxyDisabled (3.27s)2811=== CONT TestClientErrorHandling/InvalidAuthToken28122026/10/01 09:34:14 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28132026/10/01 09:34:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.194012ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28142026/10/01 09:34:14 OK 20241026095416_initial_model.sql (194.97ms)28152026/10/01 09:34:14 OK 20251210153512_drop_unused_gin_index.sql (19.26ms)2816--- PASS: TestReadProxyConditionalGet (3.13s)2817=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts28182026/10/01 09:34:14 INFO Received request for more parts method=POST path=/28192026/10/01 09:34:14 OK 20251218171726_add_pins.sql (25.91ms)2820=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure28212026/10/01 09:34:14 INFO Received uploads request method=POST path=/28222026/10/01 09:34:15 OK 20260628120000_add_object_size_and_stats.sql (37.98ms)28232026/10/01 09:34:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.575524ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28242026/10/01 09:34:15 OK 20260905000000_add_claims.sql (59.83ms)28252026/10/01 09:34:15 OK 20260920000000_drop_claims.sql (28.76ms)28262026/10/01 09:34:15 OK 20260923120000_add_pushes.sql (12.43ms)28272026/10/01 09:34:15 goose: successfully migrated database to version: 2026092312000028282026/10/01 09:34:15 OK 1_commit_pending_closure.sql (952.54µs)28292026/10/01 09:34:15 OK 2_object_stats_trigger.sql (196.58µs)28302026/10/01 09:34:15 OK 3_commit_push.sql (188.46µs)28312026/10/01 09:34:15 goose: up to current file version: 32832--- PASS: TestGetExistingObjectsLocksRows (3.06s)2833=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart28342026/10/01 09:34:15 INFO Received complete multipart upload request method=POST path=/2835=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info28362026/10/01 09:34:15 INFO Received uploads request method=POST path=/2837=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key28382026/10/01 09:34:15 INFO Received complete multipart upload request method=POST path=/2839=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key28402026/10/01 09:34:15 INFO Received request for more parts method=POST path=/2841=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal28422026/10/01 09:34:15 INFO Received uploads request method=POST path=/2843--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2844 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2845 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2846 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2847 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2848=== CONT TestCacheConfigHandler/full_config,_no_issuer2849=== CONT TestCacheConfigHandler/no_signing_keys2850=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2851=== CONT TestCacheConfigHandler/no_cache_url_configured2852--- PASS: TestCacheConfigHandler (0.00s)2853 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2854 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2855 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2856 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2857=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2858=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2859=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected28602026/10/01 09:34:15 WARN Authentication failed token_preview=eyJhbGciOi...KSVNHwJ9Rw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2861=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected28622026/10/01 09:34:15 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]2863=== CONT TestService_RequireScope_OIDC/builder_may_write2864=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2865=== CONT TestService_RequireScope_OIDC/writer_implies_read2866=== CONT TestService_RequireScope_OIDC/reader_may_read2867=== CONT TestService_RequireScope_OIDC/static_token_may_write2868=== CONT TestService_RequireScope_OIDC/static_token_may_admin2869=== CONT TestService_RequireScope_OIDC/reader_may_not_write2870=== CONT TestService_RequireScope_OIDC/ops_may_not_write2871=== CONT TestService_RequireScope_OIDC/ops_may_admin2872=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2873=== CONT TestPush_RejectsBadRequests/no_roots28742026/10/01 09:34:15 INFO Received push request method=POST path=/api/pushes2875=== CONT TestPush_RejectsBadRequests/bad_root28762026/10/01 09:34:15 INFO Received push request method=POST path=/api/pushes2877=== CONT TestPush_RejectsBadRequests/no_objects28782026/10/01 09:34:15 INFO Received push request method=POST path=/api/pushes2879=== CONT TestPush_RejectsBadRequests/root_not_in_objects28802026/10/01 09:34:15 INFO Received push request method=POST path=/api/pushes2881--- PASS: TestPush_RejectsBadRequests (3.48s)2882 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2883 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2884 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2885 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2886--- PASS: TestService_RequireScope_OIDC (1.88s)2887 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2888 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2889 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2890 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2891 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2892 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2893 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2894 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2895 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2896 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2897--- PASS: TestService_AuthMiddleware_OIDC (1.98s)2898 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2899 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2900 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2901 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2902--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2903 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2904 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2905 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)29062026-10-01 09:34:15.326 UTC [41532] ERROR: relation "goose_db_version" does not exist at character 3629072026-10-01 09:34:15.326 UTC [41532] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29082026-10-01 09:34:15.435 UTC [41533] ERROR: relation "goose_db_version" does not exist at character 3629092026-10-01 09:34:15.435 UTC [41533] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2910--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.24s)29112026/10/01 09:34:15 OK 20241026095416_initial_model.sql (93.19ms)29122026/10/01 09:34:15 OK 20251210153512_drop_unused_gin_index.sql (15.16ms)29132026/10/01 09:34:15 OK 20251218171726_add_pins.sql (9.65ms)29142026/10/01 09:34:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.170134ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29152026/10/01 09:34:15 OK 20260628120000_add_object_size_and_stats.sql (8.52ms)29162026-10-01 09:34:15.517 UTC [41534] ERROR: relation "goose_db_version" does not exist at character 3629172026-10-01 09:34:15.517 UTC [41534] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29182026/10/01 09:34:15 OK 20260905000000_add_claims.sql (21.43ms)29192026/10/01 09:34:15 OK 20260920000000_drop_claims.sql (4.15ms)29202026/10/01 09:34:15 OK 20260923120000_add_pushes.sql (7.16ms)29212026/10/01 09:34:15 goose: successfully migrated database to version: 2026092312000029222026/10/01 09:34:15 OK 1_commit_pending_closure.sql (2.44ms)29232026/10/01 09:34:15 OK 2_object_stats_trigger.sql (532.83µs)29242026/10/01 09:34:15 OK 3_commit_push.sql (345.04µs)29252026/10/01 09:34:15 goose: up to current file version: 329262026/10/01 09:34:15 OK 20241026095416_initial_model.sql (52.14ms)29272026/10/01 09:34:15 OK 20251210153512_drop_unused_gin_index.sql (6.73ms)29282026/10/01 09:34:15 OK 20251218171726_add_pins.sql (7.6ms)29292026/10/01 09:34:15 OK 20260628120000_add_object_size_and_stats.sql (26.41ms)29302026-10-01 09:34:15.581 UTC [41535] ERROR: relation "goose_db_version" does not exist at character 3629312026-10-01 09:34:15.581 UTC [41535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29322026/10/01 09:34:15 OK 20260905000000_add_claims.sql (17.55ms)29332026/10/01 09:34:15 OK 20260920000000_drop_claims.sql (13.97ms)2934--- PASS: TestReadProxyInvalidPath (2.94s)29352026/10/01 09:34:15 OK 20241026095416_initial_model.sql (75.71ms)29362026/10/01 09:34:15 OK 20260923120000_add_pushes.sql (11.54ms)29372026/10/01 09:34:15 goose: successfully migrated database to version: 2026092312000029382026/10/01 09:34:15 OK 1_commit_pending_closure.sql (3.54ms)29392026/10/01 09:34:15 OK 2_object_stats_trigger.sql (638.21µs)29402026/10/01 09:34:15 OK 3_commit_push.sql (454.5µs)29412026/10/01 09:34:15 goose: up to current file version: 329422026/10/01 09:34:15 OK 20251210153512_drop_unused_gin_index.sql (17.26ms)29432026/10/01 09:34:15 OK 20251218171726_add_pins.sql (26.81ms)29442026/10/01 09:34:15 OK 20260628120000_add_object_size_and_stats.sql (11.22ms)29452026/10/01 09:34:15 OK 20260905000000_add_claims.sql (30.51ms)29462026/10/01 09:34:15 OK 20241026095416_initial_model.sql (89.66ms)29472026/10/01 09:34:15 OK 20260920000000_drop_claims.sql (3.49ms)29482026/10/01 09:34:15 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)29492026/10/01 09:34:15 OK 20260923120000_add_pushes.sql (14.56ms)29502026/10/01 09:34:15 goose: successfully migrated database to version: 2026092312000029512026/10/01 09:34:15 OK 1_commit_pending_closure.sql (4.42ms)29522026/10/01 09:34:15 OK 2_object_stats_trigger.sql (909.75µs)29532026/10/01 09:34:15 OK 3_commit_push.sql (762.96µs)29542026/10/01 09:34:15 goose: up to current file version: 329552026/10/01 09:34:15 OK 20251218171726_add_pins.sql (21.72ms)29562026/10/01 09:34:15 OK 20260628120000_add_object_size_and_stats.sql (10.96ms)29572026/10/01 09:34:15 OK 20260905000000_add_claims.sql (27.46ms)29582026/10/01 09:34:15 OK 20260920000000_drop_claims.sql (16.83ms)29592026/10/01 09:34:15 OK 20260923120000_add_pushes.sql (9.8ms)29602026/10/01 09:34:15 goose: successfully migrated database to version: 2026092312000029612026/10/01 09:34:15 OK 1_commit_pending_closure.sql (4.71ms)29622026/10/01 09:34:15 OK 2_object_stats_trigger.sql (871.42µs)29632026/10/01 09:34:15 OK 3_commit_push.sql (686.71µs)29642026/10/01 09:34:15 goose: up to current file version: 32965--- PASS: TestReadProxy404 (2.48s)29662026-10-01 09:34:15.897 UTC [41536] ERROR: relation "goose_db_version" does not exist at character 3629672026-10-01 09:34:15.897 UTC [41536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29682026/10/01 09:34:16 INFO Received uploads request method=POST path=/api/pending_closures29692026/10/01 09:34:16 INFO Aborted multipart uploads count=029702026/10/01 09:34:16 WARN Force mode enabled - objects will be deleted immediately without grace period29712026/10/01 09:34:16 OK 20241026095416_initial_model.sql (98.96ms)29722026/10/01 09:34:16 OK 20251210153512_drop_unused_gin_index.sql (7.12ms)29732026/10/01 09:34:16 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=029742026/10/01 09:34:16 INFO Vacuumed table table=pending_closures29752026/10/01 09:34:16 INFO Vacuumed table table=pending_objects29762026/10/01 09:34:16 INFO Vacuumed table table=multipart_uploads29772026/10/01 09:34:16 INFO Vacuumed table table=closures29782026/10/01 09:34:16 OK 20251218171726_add_pins.sql (21.31ms)29792026/10/01 09:34:16 INFO Vacuumed table table=objects29802026/10/01 09:34:16 OK 20260628120000_add_object_size_and_stats.sql (18.49ms)29812026/10/01 09:34:16 OK 20260905000000_add_claims.sql (42.19ms)29822026/10/01 09:34:16 OK 20260920000000_drop_claims.sql (24.31ms)29832026/10/01 09:34:16 OK 20260923120000_add_pushes.sql (14.42ms)29842026/10/01 09:34:16 goose: successfully migrated database to version: 2026092312000029852026/10/01 09:34:16 OK 1_commit_pending_closure.sql (4.47ms)29862026/10/01 09:34:16 OK 2_object_stats_trigger.sql (1.05ms)29872026/10/01 09:34:16 OK 3_commit_push.sql (922.13µs)29882026/10/01 09:34:16 goose: up to current file version: 329892026/10/01 09:34:16 INFO Received uploads request method=POST path=/api/pending_closures29902026/10/01 09:34:16 INFO Aborted multipart uploads count=029912026/10/01 09:34:16 WARN Force mode enabled - objects will be deleted immediately without grace period29922026/10/01 09:34:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=029932026/10/01 09:34:16 INFO Vacuumed table table=pending_closures29942026/10/01 09:34:16 INFO Vacuumed table table=pending_objects29952026/10/01 09:34:16 INFO Vacuumed table table=multipart_uploads29962026/10/01 09:34:16 INFO Vacuumed table table=closures29972026/10/01 09:34:16 INFO Vacuumed table table=objects2998--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2999 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.52s)3000 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.63s)30012026/10/01 09:34:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.740279748s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30022026/10/01 09:34:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30032026/10/01 09:34:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30042026/10/01 09:34:18 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-config30052026/10/01 09:34:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.345291ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30062026/10/01 09:34:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.299164ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30072026/10/01 09:34:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=863.206892ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30082026/10/01 09:34:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.726899507s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30092026/10/01 09:34:21 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"30102026/10/01 09:34:21 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-config30112026/10/01 09:34:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.26625ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30122026/10/01 09:34:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.783305ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30132026/10/01 09:34:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.015942ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30142026/10/01 09:34:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.750225311s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30152026/10/01 09:34:24 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_closures30162026/10/01 09:34:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.931163ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30172026/10/01 09:34:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.568939ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30182026/10/01 09:34:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.670031ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30192026/10/01 09:34:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.471710129s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3020--- PASS: TestClientErrorHandling (0.00s)3021 --- PASS: TestClientErrorHandling/InvalidStorePath (2.42s)3022 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.87s)3023 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.42s)3024PASS3025{"timestamp":"2026-10-01T09:34:27.893516Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49263","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}30262026-10-01 09:34:28.001 UTC [41112] LOG: received smart shutdown request30272026-10-01 09:34:28.002 UTC [41112] LOG: background worker "logical replication launcher" (PID 41122) exited with exit code 130282026-10-01 09:34:28.027 UTC [41117] LOG: shutting down30292026-10-01 09:34:28.027 UTC [41117] LOG: checkpoint starting: shutdown immediate30302026-10-01 09:34:29.255 UTC [41117] LOG: checkpoint complete: wrote 12877 buffers (78.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.723 s, sync=0.474 s, total=1.229 s; sync files=27975, longest=0.001 s, average=0.001 s; distance=393898 kB, estimate=393898 kB; lsn=0/19837A40, redo lsn=0/19837A4030312026-10-01 09:34:29.261 UTC [41112] LOG: database system is shut down3032Running OIDC tests...3033=== RUN TestAudienceForIssuer3034=== PAUSE TestAudienceForIssuer3035=== RUN TestGlobMatch3036=== PAUSE TestGlobMatch3037=== RUN TestValidateToken_ValidToken3038=== PAUSE TestValidateToken_ValidToken3039=== RUN TestValidateToken_WrongAudience3040=== PAUSE TestValidateToken_WrongAudience3041=== RUN TestValidateToken_Expired3042=== PAUSE TestValidateToken_Expired3043=== RUN TestValidateToken_BoundClaimsMismatch3044=== PAUSE TestValidateToken_BoundClaimsMismatch3045=== RUN TestValidateToken_BoundSubjectMismatch3046=== PAUSE TestValidateToken_BoundSubjectMismatch3047=== RUN TestValidateToken_MultipleProviders3048=== PAUSE TestValidateToken_MultipleProviders3049=== RUN TestValidateToken_NoMatchingProvider3050=== PAUSE TestValidateToken_NoMatchingProvider3051=== RUN TestValidateToken_KubernetesServiceAccount3052=== PAUSE TestValidateToken_KubernetesServiceAccount3053=== RUN TestNewValidator_KubernetesRequiresCA3054=== PAUSE TestNewValidator_KubernetesRequiresCA3055=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3056=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3057=== RUN TestPins_ReservedForMatchingRule3058=== PAUSE TestPins_ReservedForMatchingRule3059=== RUN TestPins_TopLevelShorthand3060=== PAUSE TestPins_TopLevelShorthand3061=== RUN TestPins_ConfigValidation3062=== PAUSE TestPins_ConfigValidation3063=== RUN TestScopes_LegacyProviderDefaultsToWrite3064=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3065=== RUN TestScopes_Rules3066=== PAUSE TestScopes_Rules3067=== RUN TestScopes_ConfigValidation3068=== PAUSE TestScopes_ConfigValidation3069=== CONT TestAudienceForIssuer3070--- PASS: TestAudienceForIssuer (0.00s)3071=== CONT TestValidateToken_KubernetesServiceAccount3072=== CONT TestValidateToken_NoMatchingProvider3073=== CONT TestPins_ConfigValidation3074=== CONT TestValidateToken_MultipleProviders3075=== CONT TestValidateToken_BoundSubjectMismatch3076=== CONT TestValidateToken_BoundClaimsMismatch3077=== CONT TestValidateToken_Expired3078=== CONT TestValidateToken_WrongAudience3079--- PASS: TestPins_ConfigValidation (0.01s)3080=== CONT TestScopes_Rules3081=== CONT TestValidateToken_ValidToken3082=== CONT TestGlobMatch3083=== RUN TestGlobMatch/foo_foo3084=== PAUSE TestGlobMatch/foo_foo3085=== RUN TestGlobMatch/foo_bar3086=== PAUSE TestGlobMatch/foo_bar3087=== RUN TestGlobMatch/*_3088=== PAUSE TestGlobMatch/*_3089=== RUN TestGlobMatch/*_anything3090=== PAUSE TestGlobMatch/*_anything3091=== RUN TestGlobMatch/foo*_foo3092=== PAUSE TestGlobMatch/foo*_foo3093=== RUN TestGlobMatch/foo*_foobar3094=== PAUSE TestGlobMatch/foo*_foobar3095=== RUN TestGlobMatch/foo*_bar3096=== PAUSE TestGlobMatch/foo*_bar3097=== RUN TestGlobMatch/*bar_bar3098=== PAUSE TestGlobMatch/*bar_bar3099=== RUN TestGlobMatch/*bar_foobar3100=== PAUSE TestGlobMatch/*bar_foobar3101=== RUN TestGlobMatch/*bar_foo3102=== PAUSE TestGlobMatch/*bar_foo3103=== RUN TestGlobMatch/foo*bar_foobar3104=== PAUSE TestGlobMatch/foo*bar_foobar3105=== RUN TestGlobMatch/foo*bar_foo123bar3106=== PAUSE TestGlobMatch/foo*bar_foo123bar3107=== RUN TestGlobMatch/foo*bar_foobarbaz3108=== PAUSE TestGlobMatch/foo*bar_foobarbaz3109=== RUN TestGlobMatch/*/*_foo/bar3110=== PAUSE TestGlobMatch/*/*_foo/bar3111=== RUN TestGlobMatch/*/*_foo3112=== PAUSE TestGlobMatch/*/*_foo3113=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3114=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3115=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03116=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03117=== RUN TestGlobMatch/refs/*/main_refs/heads/main3118=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3119=== RUN TestGlobMatch/fo?_foo3120=== PAUSE TestGlobMatch/fo?_foo3121=== RUN TestGlobMatch/fo?_fo3122=== PAUSE TestGlobMatch/fo?_fo3123=== RUN TestGlobMatch/fo?_fooo3124=== PAUSE TestGlobMatch/fo?_fooo3125=== RUN TestGlobMatch/?oo_foo3126=== PAUSE TestGlobMatch/?oo_foo3127=== RUN TestGlobMatch/?oo_boo3128=== PAUSE TestGlobMatch/?oo_boo3129=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3130=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3131=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3132=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3133=== CONT TestScopes_ConfigValidation3134--- PASS: TestScopes_ConfigValidation (0.00s)3135=== CONT TestPins_ReservedForMatchingRule31362026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49415/oidc3137--- PASS: TestValidateToken_ValidToken (0.04s)3138=== CONT TestPins_TopLevelShorthand31392026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49417/oidc3140--- PASS: TestValidateToken_Expired (0.06s)3141=== CONT TestValidateToken_KubernetesIssuerFromOwnToken31422026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49419/oidc31432026/10/01 09:34:30 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:49421/oidc3144--- PASS: TestValidateToken_WrongAudience (0.07s)3145=== CONT TestNewValidator_KubernetesRequiresCA31462026/10/01 09:34:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49414/oidc3147--- PASS: TestValidateToken_MultipleProviders (0.07s)3148=== CONT TestScopes_LegacyProviderDefaultsToWrite31492026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49425/oidc3150--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)3151=== CONT TestGlobMatch/foo_foo3152=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3153=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3154=== CONT TestGlobMatch/?oo_boo3155=== CONT TestGlobMatch/?oo_foo3156=== CONT TestGlobMatch/fo?_fooo3157=== CONT TestGlobMatch/fo?_fo3158=== CONT TestGlobMatch/fo?_foo3159=== CONT TestGlobMatch/refs/*/main_refs/heads/main3160=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03161=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3162=== CONT TestGlobMatch/*/*_foo3163=== CONT TestGlobMatch/*/*_foo/bar3164=== CONT TestGlobMatch/foo*bar_foobarbaz3165=== CONT TestGlobMatch/foo*bar_foo123bar3166=== CONT TestGlobMatch/foo*bar_foobar3167=== CONT TestGlobMatch/*bar_foo3168=== CONT TestGlobMatch/*bar_foobar3169=== CONT TestGlobMatch/*bar_bar3170=== CONT TestGlobMatch/foo*_bar3171=== CONT TestGlobMatch/foo*_foobar3172=== CONT TestGlobMatch/foo*_foo3173=== CONT TestGlobMatch/*_anything3174=== CONT TestGlobMatch/*_3175=== CONT TestGlobMatch/foo_bar3176--- PASS: TestGlobMatch (0.00s)3177 --- PASS: TestGlobMatch/foo_foo (0.00s)3178 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3179 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3180 --- PASS: TestGlobMatch/?oo_boo (0.00s)3181 --- PASS: TestGlobMatch/?oo_foo (0.00s)3182 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3183 --- PASS: TestGlobMatch/fo?_fo (0.00s)3184 --- PASS: TestGlobMatch/fo?_foo (0.00s)3185 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3186 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3187 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3188 --- PASS: TestGlobMatch/*/*_foo (0.00s)3189 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3190 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3191 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3192 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3193 --- PASS: TestGlobMatch/*bar_foo (0.00s)3194 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3195 --- PASS: TestGlobMatch/*bar_bar (0.00s)3196 --- PASS: TestGlobMatch/foo*_bar (0.00s)3197 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3198 --- PASS: TestGlobMatch/foo*_foo (0.00s)3199 --- PASS: TestGlobMatch/*_anything (0.00s)3200 --- PASS: TestGlobMatch/*_ (0.00s)3201 --- PASS: TestGlobMatch/foo_bar (0.00s)32022026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49429/oidc32032026/10/01 09:34:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:494273204--- PASS: TestScopes_Rules (0.10s)3205--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)32062026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49431/oidc3207--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)32082026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49433/oidc32092026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49435/oidc3210--- PASS: TestPins_ReservedForMatchingRule (0.11s)3211--- PASS: TestPins_TopLevelShorthand (0.08s)32122026/10/01 09:34:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49437/oidc3213--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)32142026/10/01 09:34:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49424/oidc3215--- PASS: TestValidateToken_NoMatchingProvider (0.17s)32162026/10/01 09:34:30 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233217--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)32182026/10/01 09:34:30 http: TLS handshake error from 127.0.0.1:49444: read tcp 127.0.0.1:49443->127.0.0.1:49444: use of closed network connection3219--- PASS: TestNewValidator_KubernetesRequiresCA (0.12s)3220PASS3221Running hook tests...3222=== RUN TestSendPathsEmpty3223=== PAUSE TestSendPathsEmpty3224=== RUN TestQueueEnqueueAndFetch3225=== PAUSE TestQueueEnqueueAndFetch3226=== RUN TestQueueDeduplication3227=== PAUSE TestQueueDeduplication3228=== RUN TestQueueRemove3229=== PAUSE TestQueueRemove3230=== RUN TestQueueFetchBatchLimit3231=== PAUSE TestQueueFetchBatchLimit3232=== RUN TestQueueRetryMovesToBack3233=== PAUSE TestQueueRetryMovesToBack3234=== RUN TestQueueFetchRemoveLifecycle3235=== PAUSE TestQueueFetchRemoveLifecycle3236=== RUN TestQueueConcurrentWriters3237=== PAUSE TestQueueConcurrentWriters3238=== RUN TestQueueRemoveLargeClosure3239=== PAUSE TestQueueRemoveLargeClosure3240=== RUN TestServerClientIntegration3241=== PAUSE TestServerClientIntegration3242=== RUN TestServerQueueError3243=== PAUSE TestServerQueueError3244=== RUN TestGetListenerSocketActivation3245 server_test.go:210: === RUN TestGetListenerSocketActivation3246 --- PASS: TestGetListenerSocketActivation (0.00s)3247 PASS3248 3249--- PASS: TestGetListenerSocketActivation (0.01s)3250=== RUN TestDrainIsolatesPoisonPath3251=== PAUSE TestDrainIsolatesPoisonPath3252=== RUN TestRunNotBlockedByPoisonHead3253=== PAUSE TestRunNotBlockedByPoisonHead3254=== RUN TestDrainGivesUpWhenServerDown3255=== PAUSE TestDrainGivesUpWhenServerDown3256=== RUN TestFailedPathPrunedByLaterClosure3257=== PAUSE TestFailedPathPrunedByLaterClosure3258=== RUN TestWorkerUploadsAndRemoves3259=== PAUSE TestWorkerUploadsAndRemoves3260=== RUN TestWorkerSkipsGCdPaths3261=== PAUSE TestWorkerSkipsGCdPaths3262=== RUN TestWorkerPrunesClosureDeps3263=== PAUSE TestWorkerPrunesClosureDeps3264=== RUN TestDrainTimeout3265=== PAUSE TestDrainTimeout3266=== CONT TestSendPathsEmpty3267--- PASS: TestSendPathsEmpty (0.00s)3268=== CONT TestServerClientIntegration3269=== CONT TestServerQueueError3270=== CONT TestWorkerUploadsAndRemoves3271=== CONT TestDrainGivesUpWhenServerDown3272=== CONT TestFailedPathPrunedByLaterClosure3273=== CONT TestWorkerPrunesClosureDeps3274=== CONT TestWorkerSkipsGCdPaths3275=== CONT TestDrainTimeout3276=== CONT TestQueueDeduplication3277=== CONT TestDrainIsolatesPoisonPath32782026/10/01 09:34:31 ERROR Failed to queue paths error="permission denied" count=13279--- PASS: TestServerClientIntegration (0.00s)3280=== CONT TestRunNotBlockedByPoisonHead3281--- PASS: TestServerQueueError (0.00s)3282=== CONT TestQueueFetchRemoveLifecycle32832026/10/01 09:34:31 INFO Upload queue status pending=232842026/10/01 09:34:31 INFO Upload queue status pending=232852026/10/01 09:34:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-41057-1805751233/TestWorkerSkipsGCdPaths2942861245/002/nonexistent32862026/10/01 09:34:31 INFO Uploading batch count=232872026/10/01 09:34:31 INFO Uploading batch count=132882026/10/01 09:34:31 INFO Uploading batch count=232892026/10/01 09:34:31 INFO Uploading batch count=432902026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=432912026/10/01 09:34:31 INFO Upload queue status pending=232922026/10/01 09:34:31 INFO Uploading batch count=13293--- PASS: TestQueueFetchRemoveLifecycle (0.01s)3294=== CONT TestQueueRemoveLargeClosure32952026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainIsolatesPoisonPath1852652249/002/bbb32962026/10/01 09:34:31 INFO Uploading batch count=132972026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=132982026/10/01 09:34:31 INFO Upload queue status pending=332992026/10/01 09:34:31 INFO Uploading batch count=133002026/10/01 09:34:31 INFO Uploading batch count=133012026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=13302--- PASS: TestQueueDeduplication (0.01s)3303=== CONT TestQueueConcurrentWriters33042026/10/01 09:34:31 INFO Uploading batch count=133052026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=133062026/10/01 09:34:31 INFO Uploading batch count=133072026/10/01 09:34:31 INFO Uploading batch count=133082026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=133092026/10/01 09:34:31 INFO Uploading batch count=233102026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=233112026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainGivesUpWhenServerDown23534839/002/a33122026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainGivesUpWhenServerDown23534839/002/b33132026/10/01 09:34:31 INFO Uploading batch count=133142026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=133152026/10/01 09:34:31 INFO Uploading batch count=233162026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=233172026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainGivesUpWhenServerDown23534839/002/c33182026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainGivesUpWhenServerDown23534839/002/d33192026/10/01 09:34:31 INFO Uploading batch count=233202026/10/01 09:34:31 ERROR Upload failed error="upload failed" count=233212026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainGivesUpWhenServerDown23534839/002/e33222026/10/01 09:34:31 ERROR Drain finished with paths left in queue remaining=133232026/10/01 09:34:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-41057-1805751233/TestDrainGivesUpWhenServerDown23534839/002/f33242026/10/01 09:34:31 ERROR Drain finished with paths left in queue remaining=103325--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)3326=== CONT TestQueueFetchBatchLimit3327--- PASS: TestDrainIsolatesPoisonPath (0.01s)3328=== CONT TestQueueRetryMovesToBack3329--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3330=== CONT TestQueueRemove3331--- PASS: TestQueueFetchBatchLimit (0.00s)3332=== CONT TestQueueEnqueueAndFetch3333--- PASS: TestQueueRetryMovesToBack (0.00s)3334--- PASS: TestQueueRemove (0.00s)3335--- PASS: TestQueueEnqueueAndFetch (0.00s)3336--- PASS: TestWorkerUploadsAndRemoves (0.03s)3337--- PASS: TestWorkerSkipsGCdPaths (0.03s)3338--- PASS: TestWorkerPrunesClosureDeps (0.03s)3339--- PASS: TestQueueRemoveLargeClosure (0.05s)3340--- PASS: TestQueueConcurrentWriters (0.15s)33412026/10/01 09:34:31 ERROR Upload failed error="context deadline exceeded" count=233422026/10/01 09:34:31 ERROR Drain finished with paths left in queue remaining=43343--- PASS: TestDrainTimeout (0.21s)33442026/10/01 09:34:32 INFO Uploading batch count=133452026/10/01 09:34:32 INFO Uploading batch count=133462026/10/01 09:34:32 INFO Uploading batch count=133472026/10/01 09:34:32 ERROR Upload failed error="upload failed" count=133482026/10/01 09:34:32 INFO Uploading batch count=133492026/10/01 09:34:32 ERROR Upload failed error="upload failed" count=133502026/10/01 09:34:32 INFO Uploading batch count=133512026/10/01 09:34:32 ERROR Upload failed error="upload failed" count=133522026/10/01 09:34:32 INFO Uploading batch count=133532026/10/01 09:34:32 ERROR Upload failed error="upload failed" count=133542026/10/01 09:34:32 ERROR Drain finished with paths left in queue remaining=13355--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3356PASS