niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #299
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestSetClientTLSErrors97=== CONT TestFileTokenReadsAndCaches98=== CONT TestShellSplit99=== CONT TestSetClientTLSDoesNotMutateDefaultTransport100=== CONT TestResolveStorePath101=== CONT TestSetClientTLS102=== CONT TestClientSignaturesByStorePath103=== CONT TestStreamPushReportsSignatures104=== CONT TestStreamPushRequestLine105=== CONT TestStreamPushGivesUpOnDeadServer106=== CONT TestStreamPushIsolatesFailures107=== CONT TestStreamPushBatchesUnderLoad108=== CONT TestStreamPushReportsEveryPath109=== CONT TestShellSplitErrors110=== CONT TestScriptTokenScriptFails111=== CONT TestScriptTokenEmptyCommand112=== CONT TestFileTokenMissing113=== CONT TestScriptTokenNoExpiryRerunsEveryCall114=== CONT TestFileTokenEmpty115=== CONT TestScriptTokenBadJSON116=== CONT TestStaticToken117=== CONT TestPathInfoCACompatibility118=== CONT TestScriptTokenEmptyToken119=== CONT TestScriptTokenCachesUntilRefresh120=== CONT TestEncodeNixBase32WithRealHash121=== CONT TestDoWithRetry_BodyReplayedViaGetBody122--- PASS: TestShellSplit (0.00s)123=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess124=== CONT TestRateLimiterFeedback125=== CONT TestParsePathInfoJSONMultiplePaths126=== CONT TestUploadMultipart_SupersededByPeer127=== RUN TestUploadMultipart_SupersededByPeer/exists128=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths129=== PAUSE TestUploadMultipart_SupersededByPeer/exists130=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== CONT TestPathInfoHashCompatibility132=== CONT TestParsePathInfoJSON1332026/10/01 08:23:50 ERROR Upload failed error="bad path" count=3134--- PASS: TestClientSignaturesByStorePath (0.00s)135--- PASS: TestScriptTokenEmptyCommand (0.00s)136--- PASS: TestFileTokenReadsAndCaches (0.00s)137--- PASS: TestStaticToken (0.00s)1382026/10/01 08:23:50 ERROR Upload failed error="connection refused" count=20139--- PASS: TestShellSplitErrors (0.00s)140--- PASS: TestEncodeNixBase32WithRealHash (0.00s)141--- PASS: TestScriptTokenScriptFails (0.00s)142--- PASS: TestResolveStorePath (0.00s)1432026/10/01 08:23:50 WARN Rate limiter enabled after throttle name=server-test rate=51442026/10/01 08:23:50 ERROR Upload failed error=boom count=11452026/10/01 08:23:50 ERROR Server seems unavailable, giving up on batch untried=171462026/10/01 08:23:50 ERROR Upload failed error=boom count=1147=== RUN TestRateLimiterFeedback/429_enables_limiter148=== PAUSE TestRateLimiterFeedback/429_enables_limiter149=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== RUN TestUploadMultipart_SupersededByPeer/missing151=== PAUSE TestUploadMultipart_SupersededByPeer/missing152=== RUN TestPathInfoCACompatibility/null_ca_field153--- PASS: TestScriptTokenBadJSON (0.00s)154--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)155--- PASS: TestStreamPushIsolatesFailures (0.00s)156--- PASS: TestStreamPushReportsEveryPath (0.00s)157--- PASS: TestStreamPushReportsSignatures (0.01s)158=== CONT TestEncodeNixBase32159=== RUN TestEncodeNixBase32/test_string_hash160=== RUN TestParsePathInfoJSON/Nix_format161=== PAUSE TestEncodeNixBase32/test_string_hash162=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== CONT TestGetStorePathHash164=== RUN TestGetStorePathHash/valid_store_path165=== CONT TestDumpPathWriterError166=== RUN TestSetClientTLSErrors/missing_cert_file167=== CONT TestConvertHashToNix32168=== CONT TestDumpPathSingleFile169=== CONT TestDumpPathMatchesNix170=== RUN TestRateLimiterFeedback/503_enables_limiter171=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths172=== PAUSE TestPathInfoCACompatibility/null_ca_field173--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)174=== RUN TestEncodeNixBase32/empty_input175=== PAUSE TestEncodeNixBase32/empty_input176=== PAUSE TestParsePathInfoJSON/Nix_format177=== CONT TestUploadMultipart_SupersededByPeer/exists178=== CONT TestFilterOversizedClosures179=== RUN TestFilterOversizedClosures/no_limit_keeps_everything180=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything181=== RUN TestSetClientTLS/rejects_connection_without_client_cert182=== RUN TestPathInfoCACompatibility/old_string_format_-_text183=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)184=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon185=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon186=== CONT TestRegisterUploadedObjectReusesConnections187=== CONT TestUploadMultipart_PartsInParallel1882026/10/01 08:23:50 WARN Rate limiter enabled after throttle name=server-test rate=5189=== CONT TestPartSizeForNAR190=== PAUSE TestSetClientTLSErrors/missing_cert_file191=== RUN TestConvertHashToNix32/SRI_format_to_Nix32192=== PAUSE TestGetStorePathHash/valid_store_path1932026/10/01 08:23:50 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:32923194=== RUN TestParsePathInfoJSON/Lix_format1952026/10/01 08:23:50 WARN Rate limiter backed off name=server-test rate=51962026/10/01 08:23:50 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:32923197=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text198=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped200--- PASS: TestFileTokenEmpty (0.00s)201=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert202=== CONT TestCaseHackSuffix203=== PAUSE TestRateLimiterFeedback/503_enables_limiter204=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI205=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32206=== RUN TestPartSizeForNAR/zero_stays_at_minimum207=== PAUSE TestParsePathInfoJSON/Lix_format208=== CONT TestUploadMultipart_SupersededByPeer/missing209=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter210=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum211=== RUN TestGetStorePathHash/basename_without_hyphen_should_error212=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error213=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error216--- PASS: TestFileTokenMissing (0.00s)217--- PASS: TestScriptTokenEmptyToken (0.00s)218--- PASS: TestDoServerRequestAttachesToken (0.01s)219=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA220=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA221=== RUN TestSetClientTLS/preserves_debug_logging_transport222=== PAUSE TestSetClientTLS/preserves_debug_logging_transport223=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI224=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512225=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512226=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths227=== CONT TestEncodeNixBase32/test_string_hash228=== RUN TestConvertHashToNix32/already_Nix32_format229=== PAUSE TestConvertHashToNix32/already_Nix32_format230=== RUN TestConvertHashToNix32/invalid_format231=== PAUSE TestConvertHashToNix32/invalid_format232=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)233=== RUN TestParsePathInfoJSON/empty_input234=== PAUSE TestParsePathInfoJSON/empty_input235=== RUN TestSetClientTLSErrors/missing_key_file236=== PAUSE TestSetClientTLSErrors/missing_key_file237=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter238=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter239=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestPathInfoCACompatibility/new_structured_format_-_text242=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text243=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error244=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error245--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)246=== CONT TestEncodeNixBase32/empty_input247=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512248=== CONT TestSetClientTLS/rejects_connection_without_client_cert249=== CONT TestConvertHashToNix32/SRI_format_to_Nix32250--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)251 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)252 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)253=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon254--- PASS: TestEncodeNixBase32 (0.00s)255 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)256 --- PASS: TestEncodeNixBase32/empty_input (0.00s)257--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)258=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA259=== RUN TestParsePathInfoJSON/whitespace_only260=== PAUSE TestParsePathInfoJSON/whitespace_only261=== RUN TestParsePathInfoJSON/invalid_JSON262=== PAUSE TestParsePathInfoJSON/invalid_JSON263=== RUN TestSetClientTLSErrors/missing_ca_file264=== CONT TestGetStorePathHash/valid_store_path265=== PAUSE TestSetClientTLSErrors/missing_ca_file266=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error267=== RUN TestSetClientTLSErrors/invalid_ca_file268=== PAUSE TestSetClientTLSErrors/invalid_ca_file269=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error270=== CONT TestParsePathInfoJSON/Nix_format271=== CONT TestGetStorePathHash/basename_without_hyphen_should_error272--- PASS: TestGetStorePathHash (0.04s)273 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)274 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)275 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)276 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)277=== CONT TestParsePathInfoJSON/whitespace_only278=== CONT TestParsePathInfoJSON/empty_input279=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI280=== CONT TestSetClientTLSErrors/missing_ca_file281--- PASS: TestPathInfoHashCompatibility (0.04s)282 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)283 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)284 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)285 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)286--- PASS: TestDumpPathSingleFile (0.04s)287=== CONT TestSetClientTLSErrors/invalid_ca_file288--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)289=== CONT TestSetClientTLSErrors/missing_key_file290=== CONT TestParsePathInfoJSON/Lix_format291--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)292 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)293 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.04s)294=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method295=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== CONT TestConvertHashToNix32/invalid_format297=== CONT TestConvertHashToNix32/already_Nix32_format298=== CONT TestSetClientTLS/preserves_debug_logging_transport299=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter300=== RUN TestPartSizeForNAR/small_stays_at_minimum301=== CONT TestParsePathInfoJSON/invalid_JSON302=== RUN TestFilterOversizedClosures/all_closures_skipped303=== CONT TestSetClientTLSErrors/missing_cert_file304=== CONT TestPathInfoCACompatibility/null_ca_field305=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method306=== PAUSE TestPartSizeForNAR/small_stays_at_minimum307=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum308=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum309=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts310=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts311=== RUN TestPartSizeForNAR/1_TiB312=== PAUSE TestPartSizeForNAR/1_TiB313=== CONT TestPathInfoCACompatibility/new_structured_format_-_text314=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive315=== CONT TestPathInfoCACompatibility/old_string_format_-_text316--- PASS: TestConvertHashToNix32 (0.04s)317 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)318 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)319 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)320=== CONT TestRateLimiterFeedback/429_enables_limiter321--- PASS: TestParsePathInfoJSON (0.04s)322 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)323 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)324 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)325 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)326 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)327=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter328=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3292026/10/01 08:23:50 WARN Rate limiter enabled after throttle name=server-test rate=5330=== CONT TestRateLimiterFeedback/503_enables_limiter3312026/10/01 08:23:50 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35089332=== PAUSE TestFilterOversizedClosures/all_closures_skipped3332026/10/01 08:23:50 WARN Rate limiter backed off name=server-test rate=5334=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3352026/10/01 08:23:50 WARN Rate limiter enabled after throttle name=server-test rate=5336=== CONT TestFilterOversizedClosures/all_closures_skipped3372026/10/01 08:23:50 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33243338--- PASS: TestPathInfoCACompatibility (0.05s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)342 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)343 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3442026/10/01 08:23:50 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=50345--- PASS: TestSetClientTLSErrors (0.05s)346 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)347 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)348 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)349 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)3502026/10/01 08:23:50 WARN Rate limiter backed off name=server-test rate=5351=== RUN TestPartSizeForNAR/5_TiB_S3_max_object352=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped353=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object3542026/10/01 08:23:50 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=2000355--- PASS: TestRateLimiterFeedback (0.05s)356 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)357 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)360=== RUN TestPartSizeForNAR/capped_at_5_GiB361--- PASS: TestFilterOversizedClosures (0.04s)362 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)363 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)364 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)365=== PAUSE TestPartSizeForNAR/capped_at_5_GiB366=== CONT TestPartSizeForNAR/zero_stays_at_minimum367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPartSizeForNAR/1_TiB369=== CONT TestPartSizeForNAR/5_TiB_S3_max_object370=== CONT TestPartSizeForNAR/capped_at_5_GiB371=== CONT TestPartSizeForNAR/small_stays_at_minimum372=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts373--- PASS: TestPartSizeForNAR (0.05s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)378 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)3812026/10/01 08:23:50 http: TLS handshake error from 127.0.0.1:46966: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.05s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestStreamPushRequestLine (0.07s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathWriterError (0.09s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.13s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres3114916744/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres3114916744/data -l logfile start422423/build/postgres3114916744:5432 - no response4242026-10-01 08:23:52.003 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 08:23:52.003 UTC [128] LOG: listening on Unix socket "/build/postgres3114916744/.s.PGSQL.5432"4262026-10-01 08:23:52.009 UTC [135] LOG: database system was shut down at 2026-10-01 08:23:51 UTC4272026-10-01 08:23:52.012 UTC [128] LOG: database system is ready to accept connections428/build/postgres3114916744:5432 - accepting connections429{"timestamp":"2026-10-01T08:23:52.31156655Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2f96c29e-0143-4d38-9aff-936602fe82ac","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(392)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 08:23:52.509 UTC [567] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 08:23:52.509 UTC [567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 08:23:52 OK 20241026095416_initial_model.sql (6.96ms)4742026/10/01 08:23:52 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)4752026/10/01 08:23:52 OK 20251218171726_add_pins.sql (2.07ms)4762026/10/01 08:23:52 OK 20260628120000_add_object_size_and_stats.sql (2.08ms)4772026/10/01 08:23:52 OK 20260905000000_add_claims.sql (2.15ms)4782026/10/01 08:23:52 OK 20260920000000_drop_claims.sql (1.44ms)4792026/10/01 08:23:52 OK 20260923120000_add_pushes.sql (1.05ms)4802026/10/01 08:23:52 goose: successfully migrated database to version: 202609231200004812026/10/01 08:23:52 OK 1_commit_pending_closure.sql (1.42ms)4822026/10/01 08:23:52 OK 2_object_stats_trigger.sql (673.85µs)4832026/10/01 08:23:52 OK 3_commit_push.sql (606.36µs)4842026/10/01 08:23:52 goose: up to current file version: 34852026/10/01 08:23:52 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 08:23:53 INFO lead: released remote=192.0.2.1:12344872026/10/01 08:23:53 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 08:23:53 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 08:23:53.280 UTC [577] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 08:23:53.280 UTC [577] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 08:23:53 OK 20241026095416_initial_model.sql (6.2ms)4962026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)4972026/10/01 08:23:53 OK 20251218171726_add_pins.sql (2.34ms)4982026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (2.33ms)4992026/10/01 08:23:53 OK 20260905000000_add_claims.sql (2.41ms)5002026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (1.41ms)5012026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (955.99µs)5022026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200005032026/10/01 08:23:53 OK 1_commit_pending_closure.sql (1.31ms)5042026/10/01 08:23:53 OK 2_object_stats_trigger.sql (685.83µs)5052026/10/01 08:23:53 OK 3_commit_push.sql (521.45µs)5062026/10/01 08:23:53 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestGCTaskStore_StartNew535=== PAUSE TestGCTaskStore_StartNew536=== RUN TestGCTaskStore_DeduplicateSameParams537=== PAUSE TestGCTaskStore_DeduplicateSameParams538=== RUN TestGCTaskStore_ConflictDifferentParams539=== PAUSE TestGCTaskStore_ConflictDifferentParams540=== RUN TestGCTaskStore_GetEmpty541=== PAUSE TestGCTaskStore_GetEmpty542=== RUN TestGCTaskStore_GetReturnsLatest543=== PAUSE TestGCTaskStore_GetReturnsLatest544=== RUN TestGCTaskStore_CompletedAllowsNewTask545=== PAUSE TestGCTaskStore_CompletedAllowsNewTask546=== RUN TestGCTaskStore_PhaseUpdates547=== PAUSE TestGCTaskStore_PhaseUpdates548=== RUN TestGCTaskStore_Fail549=== PAUSE TestGCTaskStore_Fail550=== RUN TestGracefulShutdownDrainsInflight551=== PAUSE TestGracefulShutdownDrainsInflight552=== RUN TestService_healthCheckHandler553=== PAUSE TestService_healthCheckHandler554=== RUN TestService_readinessHandler555=== PAUSE TestService_readinessHandler556=== RUN TestGenerateLandingPage557=== PAUSE TestGenerateLandingPage558=== RUN TestCacheConfigHandlerMaxNarSize559=== PAUSE TestCacheConfigHandlerMaxNarSize560=== RUN TestCreatePendingClosureRejectsOversizedNAR561=== PAUSE TestCreatePendingClosureRejectsOversizedNAR562=== RUN TestNARDeduplicationMetadataUploadBug563=== PAUSE TestNARDeduplicationMetadataUploadBug564=== RUN TestMetricsInventory565=== PAUSE TestMetricsInventory566=== RUN TestService_NativeMTLS567=== PAUSE TestService_NativeMTLS568=== RUN TestServerTLSConfig569=== PAUSE TestServerTLSConfig570=== RUN TestMultipartCleanup571=== PAUSE TestMultipartCleanup572=== RUN TestObjectStatsTrigger573=== PAUSE TestObjectStatsTrigger574=== RUN TestOrphanedObjectsGC575=== PAUSE TestOrphanedObjectsGC576=== RUN TestOrphanedObjectsGCStressTest577=== PAUSE TestOrphanedObjectsGCStressTest578=== RUN TestCreatePin_ReservedPins579=== PAUSE TestCreatePin_ReservedPins580=== RUN TestParseSingleRange581=== PAUSE TestParseSingleRange582=== RUN TestProxyHeadersOnlyTrustedOnSocket583=== PAUSE TestProxyHeadersOnlyTrustedOnSocket584=== RUN TestIsValidCachePath585=== PAUSE TestIsValidCachePath586=== RUN TestReadProxyNarinfo587=== PAUSE TestReadProxyNarinfo588=== RUN TestReadProxyNarinfoAlreadyDecompressed589=== PAUSE TestReadProxyNarinfoAlreadyDecompressed590=== RUN TestReadProxyNarStreaming591=== PAUSE TestReadProxyNarStreaming592=== RUN TestReadProxy404593=== PAUSE TestReadProxy404594=== RUN TestReadProxyInvalidPath595=== PAUSE TestReadProxyInvalidPath596=== RUN TestReadProxyHead597=== PAUSE TestReadProxyHead598=== RUN TestReadProxyConditionalGet599=== PAUSE TestReadProxyConditionalGet600=== RUN TestReadProxyRootRedirectsToIndexHTML601=== PAUSE TestReadProxyRootRedirectsToIndexHTML602=== RUN TestReadProxyDisabled603=== PAUSE TestReadProxyDisabled604=== RUN TestReadRedirectNar605=== PAUSE TestReadRedirectNar606=== RUN TestReadRedirectKeepsNarinfoProxied607=== PAUSE TestReadRedirectKeepsNarinfoProxied608=== RUN TestReadProxyRangeRequest609=== PAUSE TestReadProxyRangeRequest610=== RUN TestReadRedirectUsesPublicS3URL611=== PAUSE TestReadRedirectUsesPublicS3URL612=== RUN TestPush_OverlappingRootsStoreOneRowPerKey613=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey614=== RUN TestPush_CompleteCommitsEveryRoot615=== PAUSE TestPush_CompleteCommitsEveryRoot616=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit617=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit618=== RUN TestPush_RejectsBadRequests619=== PAUSE TestPush_RejectsBadRequests620=== RUN TestPush_SignsNarinfosOfItsPendingObjects621=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects622=== RUN TestRedundantMultipartUpload623=== PAUSE TestRedundantMultipartUpload624=== RUN TestCompleteMultipartUpload_ErrorButObjectExists625=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists626=== RUN TestCompletedNarNotReofferedAcrossClosures627=== PAUSE TestCompletedNarNotReofferedAcrossClosures628=== RUN TestPresignedUploadRegisteredBeforeCommit629=== PAUSE TestPresignedUploadRegisteredBeforeCommit630=== RUN TestService_Rustfstest631=== PAUSE TestService_Rustfstest632=== RUN TestParseSize633=== PAUSE TestParseSize634=== RUN TestSkippedUploadsHandler635=== PAUSE TestSkippedUploadsHandler636=== RUN TestSystemdListenerNotActivated637--- PASS: TestSystemdListenerNotActivated (0.00s)638=== RUN TestWatchdogBeatsWhenHealthy639--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)640=== RUN TestWatchdogSkipsWhenUnhealthy6412026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:23:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"651--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)652=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle653=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle654=== RUN TestProxyWriteTimeout655=== PAUSE TestProxyWriteTimeout656=== RUN TestIsValidUploadKey657=== PAUSE TestIsValidUploadKey658=== RUN TestUploadHandlersRejectInvalidKeys659=== PAUSE TestUploadHandlersRejectInvalidKeys660=== RUN TestUploadHandlersRejectOversizedBody661=== PAUSE TestUploadHandlersRejectOversizedBody662=== RUN TestService_cleanupPendingClosuresHandler663=== PAUSE TestService_cleanupPendingClosuresHandler664=== RUN TestService_createPendingClosureHandler665=== PAUSE TestService_createPendingClosureHandler666=== RUN TestService_verifyS3Integrity667=== PAUSE TestService_verifyS3Integrity668=== RUN TestCompleteMultipartUnregistered669=== PAUSE TestCompleteMultipartUnregistered670=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT671=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT672=== CONT TestService_AuthMiddleware673=== CONT TestCompleteMultipartUnregistered674=== CONT TestForceGCDuringPushOffersSweptObject675=== CONT TestProxyHeadersOnlyTrustedOnSocket676=== CONT TestService_readinessHandler677=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT678=== CONT TestParseSingleRange679=== CONT TestCreatePin_ReservedPins680=== CONT TestOrphanedObjectsGCStressTest681=== CONT TestOrphanedObjectsGC682=== CONT TestObjectStatsTrigger683=== CONT TestMultipartCleanup684=== CONT TestServerTLSConfig685=== CONT TestService_NativeMTLS686=== CONT TestMetricsInventory687=== CONT TestNARDeduplicationMetadataUploadBug688=== CONT TestCreatePendingClosureRejectsOversizedNAR6892026/10/01 08:23:53 INFO Received uploads request method=POST path=/api/pending_closures690--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)691=== CONT TestDeduplicatedObjectsRecordedAsPending692=== CONT TestCacheConfigHandlerMaxNarSize693=== CONT TestGenerateLandingPage694=== CONT TestPinProtectsFromGC695=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection696=== CONT TestGCSweepDeliversEachKeyOnce697=== CONT TestTombstonedObjectOfferedWithoutWaiting698=== CONT TestGCSweepSkipsPendingObjects699=== RUN TestParseSingleRange/none700=== PAUSE TestParseSingleRange/none701=== RUN TestServerTLSConfig/no_client_CA702=== PAUSE TestServerTLSConfig/no_client_CA703--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)704=== CONT TestPushDedupSurvivesConcurrentGC705=== RUN TestParseSingleRange/unknown_unit706=== PAUSE TestParseSingleRange/unknown_unit707=== RUN TestServerTLSConfig/missing_CA_file708=== PAUSE TestServerTLSConfig/missing_CA_file709=== RUN TestServerTLSConfig/not_a_PEM_file710=== PAUSE TestServerTLSConfig/not_a_PEM_file711=== RUN TestParseSingleRange/multi-range_ignored712=== PAUSE TestParseSingleRange/multi-range_ignored713=== RUN TestParseSingleRange/malformed_no_dash714=== PAUSE TestParseSingleRange/malformed_no_dash715=== RUN TestParseSingleRange/malformed_both_empty716--- PASS: TestGenerateLandingPage (0.00s)717=== CONT TestGCMetrics718=== CONT TestGCBugBareHashReferences719=== PAUSE TestParseSingleRange/malformed_both_empty720=== RUN TestParseSingleRange/malformed_end_before_start721=== PAUSE TestParseSingleRange/malformed_end_before_start722=== RUN TestParseSingleRange/closed723=== PAUSE TestParseSingleRange/closed724=== RUN TestParseSingleRange/open-ended725=== PAUSE TestParseSingleRange/open-ended726=== RUN TestParseSingleRange/end_clamped_to_size727=== PAUSE TestParseSingleRange/end_clamped_to_size728=== RUN TestParseSingleRange/suffix729=== PAUSE TestParseSingleRange/suffix730=== RUN TestParseSingleRange/suffix_exceeds_size731=== PAUSE TestParseSingleRange/suffix_exceeds_size732=== RUN TestParseSingleRange/single_byte733=== PAUSE TestParseSingleRange/single_byte734=== RUN TestParseSingleRange/start_past_EOF735=== PAUSE TestParseSingleRange/start_past_EOF736=== RUN TestParseSingleRange/start_far_past_EOF737=== PAUSE TestParseSingleRange/start_far_past_EOF738=== CONT TestLeadEndsOnShutdown7392026/10/01 08:23:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32877/oidc7402026-10-01 08:23:53.712 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367412026-10-01 08:23:53.712 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026-10-01 08:23:53.759 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367432026-10-01 08:23:53.759 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7442026/10/01 08:23:53 OK 20241026095416_initial_model.sql (11.84ms)7452026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (12.92ms)7462026/10/01 08:23:53 OK 20241026095416_initial_model.sql (105.04ms)7472026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)7482026/10/01 08:23:53 OK 20251218171726_add_pins.sql (10.47ms)7492026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.84ms)7502026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (10.39ms)7512026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (10.1ms)7522026/10/01 08:23:53 OK 20260905000000_add_claims.sql (5.91ms)7532026-10-01 08:23:53.896 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367542026-10-01 08:23:53.896 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026-10-01 08:23:53.898 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367562026-10-01 08:23:53.898 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026-10-01 08:23:53.898 UTC [654] ERROR: relation "goose_db_version" does not exist at character 367582026-10-01 08:23:53.898 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026/10/01 08:23:53 OK 20260905000000_add_claims.sql (13.43ms)7602026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (14.93ms)7612026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (6.19ms)7622026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (3.23ms)7632026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200007642026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (3.44ms)7652026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200007662026/10/01 08:23:53 OK 1_commit_pending_closure.sql (3.76ms)7672026/10/01 08:23:53 OK 2_object_stats_trigger.sql (3.17ms)7682026/10/01 08:23:53 OK 1_commit_pending_closure.sql (4.49ms)7692026/10/01 08:23:53 OK 3_commit_push.sql (3.56ms)7702026/10/01 08:23:53 goose: up to current file version: 37712026/10/01 08:23:53 OK 2_object_stats_trigger.sql (3.37ms)7722026/10/01 08:23:53 OK 3_commit_push.sql (2.15ms)7732026/10/01 08:23:53 goose: up to current file version: 37742026-10-01 08:23:53.929 UTC [655] ERROR: relation "goose_db_version" does not exist at character 367752026-10-01 08:23:53.929 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026-10-01 08:23:53.929 UTC [656] ERROR: relation "goose_db_version" does not exist at character 367772026-10-01 08:23:53.929 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7782026-10-01 08:23:53.943 UTC [657] ERROR: relation "goose_db_version" does not exist at character 367792026-10-01 08:23:53.943 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026-10-01 08:23:53.948 UTC [658] ERROR: relation "goose_db_version" does not exist at character 367812026-10-01 08:23:53.948 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7822026/10/01 08:23:53 OK 20241026095416_initial_model.sql (30.48ms)7832026/10/01 08:23:53 INFO Received uploads request method=POST path=/api/pending_closures7842026-10-01 08:23:53.954 UTC [659] ERROR: relation "goose_db_version" does not exist at character 367852026-10-01 08:23:53.954 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/10/01 08:23:53 OK 20241026095416_initial_model.sql (31.18ms)7872026/10/01 08:23:53 OK 20241026095416_initial_model.sql (32.89ms)7882026-10-01 08:23:53.956 UTC [661] ERROR: relation "goose_db_version" does not exist at character 367892026-10-01 08:23:53.956 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026-10-01 08:23:53.956 UTC [660] ERROR: relation "goose_db_version" does not exist at character 367912026-10-01 08:23:53.956 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (5.9ms)7932026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (5.25ms)7942026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)7952026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.84ms)7962026-10-01 08:23:53.965 UTC [664] ERROR: relation "goose_db_version" does not exist at character 367972026-10-01 08:23:53.965 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026/10/01 08:23:53 OK 20251218171726_add_pins.sql (4.9ms)7992026-10-01 08:23:53.967 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368002026-10-01 08:23:53.967 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/10/01 08:23:53 OK 20251218171726_add_pins.sql (6.41ms)8022026-10-01 08:23:53.968 UTC [665] ERROR: relation "goose_db_version" does not exist at character 368032026-10-01 08:23:53.968 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026/10/01 08:23:53 OK 20241026095416_initial_model.sql (12.86ms)8052026-10-01 08:23:53.970 UTC [667] ERROR: relation "goose_db_version" does not exist at character 368062026-10-01 08:23:53.970 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)8082026/10/01 08:23:53 OK 20241026095416_initial_model.sql (14.7ms)8092026-10-01 08:23:53.971 UTC [666] ERROR: relation "goose_db_version" does not exist at character 368102026-10-01 08:23:53.971 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026-10-01 08:23:53.972 UTC [668] ERROR: relation "goose_db_version" does not exist at character 368122026-10-01 08:23:53.972 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (6.7ms)814--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.41s)815=== CONT TestLeadElectsOneAndHandsOver8162026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)8172026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (6.91ms)8182026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.5ms)8192026/10/01 08:23:53 OK 20260905000000_add_claims.sql (4.05ms)8202026/10/01 08:23:53 OK 20241026095416_initial_model.sql (11.9ms)8212026/10/01 08:23:53 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"822--- PASS: TestService_AuthMiddleware (0.42s)823=== CONT TestResolveDBConnectionString8242026/10/01 08:23:53 OK 20241026095416_initial_model.sql (11.43ms)825=== RUN TestResolveDBConnectionString/flag_wins8262026/10/01 08:23:53 OK 20260905000000_add_claims.sql (3.84ms)827=== PAUSE TestResolveDBConnectionString/flag_wins828=== RUN TestResolveDBConnectionString/file_when_flag_empty829=== PAUSE TestResolveDBConnectionString/file_when_flag_empty830=== RUN TestResolveDBConnectionString/missing_file_is_an_error831=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error832=== RUN TestResolveDBConnectionString/PGHOST_allows_empty833=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty834=== RUN TestResolveDBConnectionString/nothing_configured835=== PAUSE TestResolveDBConnectionString/nothing_configured836=== CONT TestClientFallsBackToClosures8372026/10/01 08:23:53 OK 20260905000000_add_claims.sql (3.58ms)8382026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (3.02ms)8392026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)8402026-10-01 08:23:53.979 UTC [669] ERROR: relation "goose_db_version" does not exist at character 368412026-10-01 08:23:53.979 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (2.52ms)8432026/10/01 08:23:53 OK 20251218171726_add_pins.sql (6.06ms)8442026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.47ms)8452026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)8462026-10-01 08:23:53.981 UTC [671] ERROR: relation "goose_db_version" does not exist at character 368472026-10-01 08:23:53.981 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (3.08ms)8492026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (3.09ms)8502026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200008512026/10/01 08:23:53 OK 20241026095416_initial_model.sql (12.53ms)8522026/10/01 08:23:53 OK 20241026095416_initial_model.sql (12.61ms)8532026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (2.44ms)8542026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200008552026/10/01 08:23:53 OK 20241026095416_initial_model.sql (13.13ms)8562026-10-01 08:23:53.983 UTC [672] ERROR: relation "goose_db_version" does not exist at character 368572026-10-01 08:23:53.983 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.11ms)8592026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (3.48ms)8602026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200008612026-10-01 08:23:53.985 UTC [675] ERROR: relation "goose_db_version" does not exist at character 368622026-10-01 08:23:53.985 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8632026/10/01 08:23:53 OK 1_commit_pending_closure.sql (3.07ms)8642026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (5.37ms)8652026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)8662026/10/01 08:23:53 OK 1_commit_pending_closure.sql (3.94ms)8672026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.26ms)8682026/10/01 08:23:53 OK 2_object_stats_trigger.sql (2.08ms)8692026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)8702026/10/01 08:23:53 OK 2_object_stats_trigger.sql (1.85ms)8712026/10/01 08:23:53 OK 1_commit_pending_closure.sql (3.88ms)8722026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)8732026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)8742026/10/01 08:23:53 OK 20241026095416_initial_model.sql (12.62ms)8752026/10/01 08:23:53 OK 20260905000000_add_claims.sql (3.9ms)8762026/10/01 08:23:53 OK 20260905000000_add_claims.sql (3.92ms)8772026/10/01 08:23:53 OK 3_commit_push.sql (1.66ms)8782026/10/01 08:23:53 goose: up to current file version: 38792026/10/01 08:23:53 OK 20241026095416_initial_model.sql (11.97ms)8802026/10/01 08:23:53 OK 3_commit_push.sql (2.12ms)8812026/10/01 08:23:53 goose: up to current file version: 38822026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.33ms)8832026/10/01 08:23:53 OK 2_object_stats_trigger.sql (2.83ms)8842026-10-01 08:23:53.992 UTC [676] ERROR: relation "goose_db_version" does not exist at character 368852026-10-01 08:23:53.992 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8862026/10/01 08:23:53 OK 20241026095416_initial_model.sql (15.85ms)8872026/10/01 08:23:53 OK 20241026095416_initial_model.sql (12.25ms)8882026/10/01 08:23:53 OK 20260628120000_add_object_size_and_stats.sql (6.97ms)8892026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)8902026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (3.91ms)8912026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (3.81ms)8922026/10/01 08:23:53 OK 3_commit_push.sql (2.08ms)8932026/10/01 08:23:53 goose: up to current file version: 38942026/10/01 08:23:53 OK 20251218171726_add_pins.sql (6.07ms)8952026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)8962026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (2ms)8972026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.28ms)8982026/10/01 08:23:53 OK 20241026095416_initial_model.sql (13.87ms)8992026/10/01 08:23:53 OK 20260905000000_add_claims.sql (4.93ms)9002026/10/01 08:23:53 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)9012026/10/01 08:23:53 OK 20251218171726_add_pins.sql (3.96ms)9022026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (2.81ms)9032026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200009042026/10/01 08:23:53 OK 20260923120000_add_pushes.sql (4.19ms)9052026/10/01 08:23:53 goose: successfully migrated database to version: 202609231200009062026/10/01 08:23:53 OK 20260905000000_add_claims.sql (4.71ms)9072026-10-01 08:23:53.998 UTC [678] ERROR: relation "goose_db_version" does not exist at character 369082026-10-01 08:23:53.998 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026/10/01 08:23:53 OK 20241026095416_initial_model.sql (14.23ms)9102026/10/01 08:23:53 OK 20260920000000_drop_claims.sql (3.78ms)9112026/10/01 08:23:53 OK 20251218171726_add_pins.sql (5.66ms)9122026/10/01 08:23:53 OK 20251218171726_add_pins.sql (4.92ms)9132026/10/01 08:23:53 OK 20251218171726_add_pins.sql (4.85ms)9142026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3ms)9152026/10/01 08:23:54 OK 20251218171726_add_pins.sql (5.09ms)9162026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)9172026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9182026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)9192026/10/01 08:23:54 OK 20241026095416_initial_model.sql (12.71ms)9202026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.32ms)9212026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.77ms)9222026/10/01 08:23:54 OK 20241026095416_initial_model.sql (12.13ms)9232026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.44ms)9242026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009252026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.54ms)9262026/10/01 08:23:54 OK 20241026095416_initial_model.sql (12.43ms)9272026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)9282026/10/01 08:23:54 OK 2_object_stats_trigger.sql (3.11ms)9292026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)9302026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)9312026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (3.83ms)9322026/10/01 08:23:54 OK 20260905000000_add_claims.sql (4.93ms)9332026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009342026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)9352026/10/01 08:23:54 OK 3_commit_push.sql (2.55ms)9362026/10/01 08:23:54 goose: up to current file version: 39372026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.53ms)9382026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.87ms)9392026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (6.83ms)9402026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)9412026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)9422026/10/01 08:23:54 OK 3_commit_push.sql (1.91ms)9432026/10/01 08:23:54 goose: up to current file version: 39442026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)9452026/10/01 08:23:54 OK 20260905000000_add_claims.sql (5.66ms)9462026/10/01 08:23:54 OK 20260905000000_add_claims.sql (5.84ms)9472026/10/01 08:23:54 OK 20251218171726_add_pins.sql (4.2ms)9482026/10/01 08:23:54 OK 20241026095416_initial_model.sql (11.92ms)9492026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.52ms)9502026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.05ms)9512026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (3.15ms)9522026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.14ms)9532026/10/01 08:23:54 OK 20251218171726_add_pins.sql (4.4ms)9542026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.53ms)9552026/10/01 08:23:54 OK 3_commit_push.sql (1.34ms)9562026/10/01 08:23:54 goose: up to current file version: 39572026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.37ms)9582026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.72ms)9592026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.82ms)9602026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)9612026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.82ms)9622026/10/01 08:23:54 OK 20260905000000_add_claims.sql (4.01ms)9632026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.78ms)9642026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.5ms)9652026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.02ms)9662026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009672026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.91ms)9682026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)9692026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2ms)9702026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009712026/10/01 08:23:54 OK 20241026095416_initial_model.sql (11.36ms)9722026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.09ms)9732026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4ms)9742026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.13ms)9752026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009762026/10/01 08:23:54 OK 3_commit_push.sql (1.59ms)9772026/10/01 08:23:54 goose: up to current file version: 39782026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.74ms)9792026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.6ms)9802026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.43ms)9812026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.92ms)9822026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.27ms)9832026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)9842026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.25ms)9852026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009862026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.92ms)9872026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009882026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.41ms)9892026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.25ms)9902026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.46ms)9912026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)9922026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.59ms)9932026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)9942026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.32ms)9952026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.39ms)9962026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009972026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.96ms)9982026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200009992026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (6.63ms)10002026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.42ms)10012026/10/01 08:23:54 OK 20241026095416_initial_model.sql (11.31ms)10022026/10/01 08:23:54 OK 3_commit_push.sql (1.9ms)10032026/10/01 08:23:54 goose: up to current file version: 310042026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.72ms)10052026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.96ms)10062026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.68ms)10072026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.75ms)10082026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)10092026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.27ms)10102026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (3.15ms)10112026/10/01 08:23:54 OK 3_commit_push.sql (1.37ms)10122026/10/01 08:23:54 goose: up to current file version: 310132026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.12ms)10142026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3ms)10152026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.48ms)10162026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.72ms)10172026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)10182026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.49ms)10192026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.34ms)10202026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.85ms)10212026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.06ms)10222026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010232026/10/01 08:23:54 OK 3_commit_push.sql (1.7ms)10242026/10/01 08:23:54 goose: up to current file version: 310252026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.66ms)10262026/10/01 08:23:54 OK 3_commit_push.sql (1.51ms)10272026/10/01 08:23:54 goose: up to current file version: 310282026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.32ms)10292026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)10302026/10/01 08:23:54 OK 3_commit_push.sql (1.72ms)10312026/10/01 08:23:54 goose: up to current file version: 310322026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.45ms)10332026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.82ms)10342026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.82ms)10352026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010362026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.48ms)10372026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.45ms)10382026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.68ms)10392026/10/01 08:23:54 OK 3_commit_push.sql (1.05ms)10402026/10/01 08:23:54 goose: up to current file version: 310412026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.93ms)10422026/10/01 08:23:54 OK 3_commit_push.sql (1.62ms)10432026/10/01 08:23:54 goose: up to current file version: 310442026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.97ms)10452026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010462026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.69ms)10472026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.13ms)10482026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010492026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.37ms)10502026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.59ms)10512026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010522026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.41ms)10532026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.73ms)10542026/10/01 08:23:54 OK 1_commit_pending_closure.sql (1.92ms)10552026/10/01 08:23:54 OK 3_commit_push.sql (1.35ms)10562026/10/01 08:23:54 goose: up to current file version: 310572026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.05ms)10582026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010592026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)10602026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.78ms)10612026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.51ms)10622026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.7ms)10632026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.02ms)10642026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.11ms)10652026/10/01 08:23:54 OK 3_commit_push.sql (1.64ms)10662026/10/01 08:23:54 goose: up to current file version: 310672026/10/01 08:23:54 OK 3_commit_push.sql (1.39ms)10682026/10/01 08:23:54 goose: up to current file version: 310692026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.88ms)10702026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3ms)10712026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010722026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.73ms)10732026/10/01 08:23:54 OK 1_commit_pending_closure.sql (3.04ms)10742026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2ms)10752026/10/01 08:23:54 OK 3_commit_push.sql (1.04ms)10762026/10/01 08:23:54 goose: up to current file version: 310772026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.96ms)10782026/10/01 08:23:54 OK 3_commit_push.sql (1.83ms)10792026/10/01 08:23:54 goose: up to current file version: 310802026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.19ms)10812026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.93ms)10822026/10/01 08:23:54 OK 3_commit_push.sql (1.23ms)10832026/10/01 08:23:54 goose: up to current file version: 310842026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.56ms)10852026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.8ms)10862026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000010872026/10/01 08:23:54 OK 3_commit_push.sql (1.15ms)10882026/10/01 08:23:54 goose: up to current file version: 310892026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.18ms)10902026/10/01 08:23:54 OK 2_object_stats_trigger.sql (700.88µs)10912026/10/01 08:23:54 OK 3_commit_push.sql (984.67µs)10922026/10/01 08:23:54 goose: up to current file version: 310932026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures10942026-10-01 08:23:54.085 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3610952026-10-01 08:23:54.085 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10962026-10-01 08:23:54.086 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3610972026-10-01 08:23:54.086 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10982026/10/01 08:23:54 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket18370807/001/proxy.sock10992026/10/01 08:23:54 INFO Starting HTTP server address=127.0.0.1:3297311002026/10/01 08:23:54 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11012026/10/01 08:23:54 INFO Shutdown signal received, draining in-flight requests timeout=10s1102--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.54s)1103=== CONT TestClientPushesUseOnePush11042026/10/01 08:23:54 OK 20241026095416_initial_model.sql (7.56ms)11052026/10/01 08:23:54 OK 20241026095416_initial_model.sql (8.28ms)11062026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)11072026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)11082026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.3ms)11092026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.21ms)11102026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (2.63ms)11112026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)11122026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.74ms)11132026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (1.82ms)11142026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.25ms)11152026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.55ms)11162026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000011172026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.81ms)11182026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.38ms)11192026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000011202026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.46ms)11212026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.5ms)11222026/10/01 08:23:54 OK 3_commit_push.sql (1.17ms)11232026/10/01 08:23:54 goose: up to current file version: 311242026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.31ms)11252026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.11ms)11262026/10/01 08:23:54 OK 3_commit_push.sql (697.1µs)11272026/10/01 08:23:54 goose: up to current file version: 311282026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/01 08:23:54 INFO Aborted multipart uploads count=011302026/10/01 08:23:54 WARN Force mode enabled - objects will be deleted immediately without grace period11312026/10/01 08:23:54 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=011322026/10/01 08:23:54 INFO Vacuumed table table=pending_closures11332026/10/01 08:23:54 INFO Vacuumed table table=pending_objects11342026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads11352026/10/01 08:23:54 INFO Vacuumed table table=closures11362026/10/01 08:23:54 INFO Vacuumed table table=objects11372026/10/01 08:23:54 INFO Received cleanup request method=DELETE path=/api/pending_closures11382026/10/01 08:23:54 INFO Aborted multipart uploads count=11139--- PASS: TestForceGCDuringPushOffersSweptObject (0.62s)1140--- PASS: TestMultipartCleanup (0.61s)1141=== CONT TestGCTaskStore_GetEmpty1142--- PASS: TestGCTaskStore_GetEmpty (0.00s)1143=== CONT TestService_healthCheckHandler1144=== CONT TestGracefulShutdownDrainsInflight11452026/10/01 08:23:54 INFO Starting HTTP server address=127.0.0.1:4085511462026/10/01 08:23:54 INFO Shutdown signal received, draining in-flight requests timeout=10s1147--- PASS: TestObjectStatsTrigger (0.62s)1148=== CONT TestGCTaskStore_Fail1149--- PASS: TestGCTaskStore_Fail (0.00s)1150=== CONT TestGCTaskStore_PhaseUpdates1151--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1152=== CONT TestGCTaskStore_CompletedAllowsNewTask1153--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1154=== CONT TestGCTaskStore_GetReturnsLatest1155--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1156=== CONT TestCacheStatsHandler1157=== NAME TestNARDeduplicationMetadataUploadBug1158 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3642517154/001/store/cbqi9biw4wxfzjqb22fywg2lf71w2qjj-file1.txt11592026-10-01 08:23:54.183 UTC [702] ERROR: relation "goose_db_version" does not exist at character 3611602026-10-01 08:23:54.183 UTC [702] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures1162--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.63s)1163=== CONT TestClientSharedPathCommittedMidPush11642026/10/01 08:23:54 OK 20241026095416_initial_model.sql (8.3ms)11652026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (959.95µs)11662026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.94ms)11672026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)11682026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.17ms)11692026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.56ms)11702026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.7ms)11712026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000011722026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.38ms)11732026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.73ms)11742026/10/01 08:23:54 OK 3_commit_push.sql (1.48ms)11752026/10/01 08:23:54 goose: up to current file version: 311762026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures11772026/10/01 08:23:54 INFO Aborted multipart uploads count=011782026/10/01 08:23:54 WARN Force mode enabled - objects will be deleted immediately without grace period1179--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1180=== CONT TestClientWithDependencies11812026/10/01 08:23:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11822026/10/01 08:23:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1183--- PASS: TestService_NativeMTLS (0.69s)1184=== CONT TestClientMultipleUploads1185--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.69s)1186=== CONT TestClientIntegration11872026/10/01 08:23:54 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=011882026/10/01 08:23:54 INFO Vacuumed table table=pending_closures11892026/10/01 08:23:54 INFO Vacuumed table table=pending_objects11902026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads11912026/10/01 08:23:54 INFO Vacuumed table table=closures11922026/10/01 08:23:54 INFO Received push request method=POST path=/api/pushes11932026/10/01 08:23:54 INFO Vacuumed table table=objects1194--- PASS: TestGCSweepDeliversEachKeyOnce (0.71s)1195=== CONT TestClientErrorHandling1196=== RUN TestClientErrorHandling/InvalidStorePath1197=== PAUSE TestClientErrorHandling/InvalidStorePath1198=== RUN TestClientErrorHandling/InvalidAuthToken1199=== PAUSE TestClientErrorHandling/InvalidAuthToken1200=== RUN TestClientErrorHandling/ServerNotAvailable1201=== PAUSE TestClientErrorHandling/ServerNotAvailable1202=== CONT TestClientCADerivations12032026-10-01 08:23:54.274 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3612042026-10-01 08:23:54.274 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12052026/10/01 08:23:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12062026/10/01 08:23:54 INFO Uploading cbqi9biw4wxfzjqb22fywg2lf71w2qjj-file1.txt (160B)12072026-10-01 08:23:54.284 UTC [753] ERROR: relation "goose_db_version" does not exist at character 3612082026-10-01 08:23:54.284 UTC [753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12092026/10/01 08:23:54 WARN Failed to register uploaded object key=cbqi9biw4wxfzjqb22fywg2lf71w2qjj.ls error="server returned 404: 404 page not found\n"12102026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12122026/10/01 08:23:54 INFO Signed narinfos id=1 count=112132026/10/01 08:23:54 INFO Uploading 1 narinfos12142026/10/01 08:23:54 OK 20241026095416_initial_model.sql (8.5ms)12152026/10/01 08:23:54 INFO Received complete push request method=POST path=/api/pushes/1/complete12162026/10/01 08:23:54 WARN Failed to register uploaded object key=cbqi9biw4wxfzjqb22fywg2lf71w2qjj.narinfo error="server returned 404: 404 page not found\n"12172026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)12182026/10/01 08:23:54 INFO Aborted multipart uploads count=012192026-10-01 08:23:54.294 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3612202026-10-01 08:23:54.294 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12212026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.45ms)12222026/10/01 08:23:54 WARN Force mode enabled - objects will be deleted immediately without grace period12232026/10/01 08:23:54 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=012242026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)12252026/10/01 08:23:54 OK 20241026095416_initial_model.sql (9.31ms)12262026/10/01 08:23:54 INFO Vacuumed table table=pending_closures12272026/10/01 08:23:54 INFO Upload complete. (75ms)12282026/10/01 08:23:54 INFO Vacuumed table table=pending_objects12292026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads12302026/10/01 08:23:54 INFO Vacuumed table table=closures12312026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)12322026/10/01 08:23:54 INFO Vacuumed table table=objects12332026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.72ms)1234=== NAME TestNARDeduplicationMetadataUploadBug1235 metadata_upload_test.go:54: Retrieved narinfo from S3:1236 StorePath: /build/TestNARDeduplicationMetadataUploadBug3642517154/001/store/cbqi9biw4wxfzjqb22fywg2lf71w2qjj-file1.txt1237 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1238 Compression: zstd1239 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1240 NarSize: 1601241 References: 1242 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12432026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (3ms)1244 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)12452026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.67ms)1246 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1247 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12482026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.16ms)12492026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000012502026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)12512026/10/01 08:23:54 OK 20241026095416_initial_model.sql (9.49ms)12522026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.99ms)1253--- PASS: TestGCMetrics (0.74s)1254=== CONT TestPush_RejectsBadRequests12552026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)12562026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.52ms)12572026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.41ms)12582026/10/01 08:23:54 OK 3_commit_push.sql (2.02ms)12592026/10/01 08:23:54 goose: up to current file version: 312602026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.45ms)12612026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.5ms)12622026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.11ms)12632026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000012642026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)12652026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.15ms)12662026/10/01 08:23:54 OK 20260905000000_add_claims.sql (13.84ms)12672026/10/01 08:23:54 OK 2_object_stats_trigger.sql (12.43ms)12682026/10/01 08:23:54 OK 3_commit_push.sql (4.38ms)12692026/10/01 08:23:54 goose: up to current file version: 312702026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (5.22ms)12712026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures12722026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (3.69ms)12732026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200001274=== NAME TestNARDeduplicationMetadataUploadBug1275 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3642517154/001/store/n8jpd6srjxfnx68p7cqd75wvgb4d4bl5-file2.txt12762026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.95ms)12772026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.83ms)12782026/10/01 08:23:54 OK 3_commit_push.sql (2.32ms)12792026/10/01 08:23:54 goose: up to current file version: 312802026-10-01 08:23:54.352 UTC [794] ERROR: relation "goose_db_version" does not exist at character 3612812026-10-01 08:23:54.352 UTC [794] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12822026-10-01 08:23:54.358 UTC [795] ERROR: relation "goose_db_version" does not exist at character 3612832026-10-01 08:23:54.358 UTC [795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12842026-10-01 08:23:54.360 UTC [796] ERROR: relation "goose_db_version" does not exist at character 3612852026-10-01 08:23:54.360 UTC [796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12862026/10/01 08:23:54 OK 20241026095416_initial_model.sql (11.62ms)12872026/10/01 08:23:54 INFO Aborted multipart uploads count=012882026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)12892026/10/01 08:23:54 WARN Force mode enabled - objects will be deleted immediately without grace period12902026-10-01 08:23:54.372 UTC [799] ERROR: relation "goose_db_version" does not exist at character 3612912026-10-01 08:23:54.372 UTC [799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12922026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.3ms)12932026/10/01 08:23:54 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=012942026/10/01 08:23:54 OK 20241026095416_initial_model.sql (11.25ms)12952026/10/01 08:23:54 OK 20241026095416_initial_model.sql (8.66ms)12962026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)12972026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)12982026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)12992026/10/01 08:23:54 INFO Vacuumed table table=pending_closures13002026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.94ms)13012026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.38ms)13022026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.89ms)13032026/10/01 08:23:54 INFO Vacuumed table table=pending_objects13042026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.57ms)13052026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads13062026/10/01 08:23:54 INFO Vacuumed table table=closures13072026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)13082026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.08ms)13092026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000013102026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)13112026/10/01 08:23:54 INFO Vacuumed table table=objects13122026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.59ms)13132026/10/01 08:23:54 OK 20241026095416_initial_model.sql (8.59ms)13142026/10/01 08:23:54 OK 1_commit_pending_closure.sql (1.77ms)13152026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)13162026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.2ms)13172026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.5ms)13182026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.27ms)13192026/10/01 08:23:54 OK 3_commit_push.sql (797.36µs)13202026/10/01 08:23:54 goose: up to current file version: 313212026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.39ms)13222026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.31ms)13232026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000013242026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.96ms)1325--- PASS: TestMetricsInventory (0.83s)1326=== CONT TestService_verifyS3Integrity1327=== NAME TestPinProtectsFromGC1328 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3304320903/001/store/2mv27b4gwhyxm6c2cxn44k9b313hwjma-pinned-file.txt1329 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3304320903/001/store/id2g16bvw7588gv81snlv7wcyi3m2afp-unpinned-file.txt13302026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.44ms)13312026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.86ms)13322026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000013332026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)1334--- PASS: TestGCSweepSkipsPendingObjects (0.83s)1335=== CONT TestService_createPendingClosureHandler13362026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.02ms)13372026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.15ms)13382026/10/01 08:23:54 OK 3_commit_push.sql (1.2ms)13392026/10/01 08:23:54 goose: up to current file version: 313402026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.3ms)13412026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.72ms)13422026/10/01 08:23:54 OK 3_commit_push.sql (591.32µs)13432026/10/01 08:23:54 goose: up to current file version: 313442026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (1.5ms)13452026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.74ms)13462026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000013472026/10/01 08:23:54 OK 1_commit_pending_closure.sql (1.79ms)13482026/10/01 08:23:54 OK 2_object_stats_trigger.sql (833.33µs)13492026/10/01 08:23:54 OK 3_commit_push.sql (1.19ms)13502026/10/01 08:23:54 goose: up to current file version: 31351=== NAME TestOrphanedObjectsGC1352 orphaned_objects_gc_test.go:290: GC Test Summary:1353 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1354 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1355 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1356 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1357 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1358--- PASS: TestOrphanedObjectsGC (0.85s)1359=== CONT TestService_cleanupPendingClosuresHandler13602026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures13612026-10-01 08:23:54.420 UTC [842] ERROR: relation "goose_db_version" does not exist at character 3613622026-10-01 08:23:54.420 UTC [842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/10/01 08:23:54 WARN readiness check failed error="closed pool"1364--- PASS: TestService_readinessHandler (0.86s)1365=== CONT TestUploadHandlersRejectOversizedBody13662026/10/01 08:23:54 INFO Received push request method=POST path=/api/pushes13672026/10/01 08:23:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13682026/10/01 08:23:54 OK 20241026095416_initial_model.sql (16.21ms)13692026/10/01 08:23:54 INFO Received push request method=POST path=/api/pushes13702026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)13712026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13722026/10/01 08:23:54 WARN Failed to register uploaded object key=n8jpd6srjxfnx68p7cqd75wvgb4d4bl5.ls error="server returned 404: 404 page not found\n"13732026/10/01 08:23:54 INFO Signed narinfos id=2 count=113742026/10/01 08:23:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13752026/10/01 08:23:54 INFO Uploading 2mv27b4gwhyxm6c2cxn44k9b313hwjma-pinned-file.txt (128B)13762026/10/01 08:23:54 INFO Uploading 1 narinfos13772026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.67ms)13782026-10-01 08:23:54.502 UTC [897] ERROR: relation "goose_db_version" does not exist at character 3613792026-10-01 08:23:54.502 UTC [897] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13802026/10/01 08:23:54 INFO Aborted multipart uploads count=013812026/10/01 08:23:54 INFO Received complete push request method=POST path=/api/pushes/2/complete13822026/10/01 08:23:54 WARN Failed to register uploaded object key=n8jpd6srjxfnx68p7cqd75wvgb4d4bl5.narinfo error="server returned 404: 404 page not found\n"13832026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13842026/10/01 08:23:54 WARN Failed to register uploaded object key=2mv27b4gwhyxm6c2cxn44k9b313hwjma.ls error="server returned 404: 404 page not found\n"13852026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13862026/10/01 08:23:54 INFO Signed narinfos id=1 count=113872026/10/01 08:23:54 INFO Uploading 1 narinfos13882026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.86ms)13892026-10-01 08:23:54.508 UTC [898] ERROR: relation "goose_db_version" does not exist at character 3613902026-10-01 08:23:54.508 UTC [898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13912026/10/01 08:23:54 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=013922026/10/01 08:23:54 INFO Upload complete. (122ms)1393=== NAME TestNARDeduplicationMetadataUploadBug13942026/10/01 08:23:54 INFO Received complete push request method=POST path=/api/pushes/1/complete1395 metadata_upload_test.go:76: Retrieved narinfo from S3:1396 StorePath: /build/TestNARDeduplicationMetadataUploadBug3642517154/001/store/n8jpd6srjxfnx68p7cqd75wvgb4d4bl5-file2.txt1397 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1398 Compression: zstd13992026/10/01 08:23:54 WARN Failed to register uploaded object key=2mv27b4gwhyxm6c2cxn44k9b313hwjma.narinfo error="server returned 404: 404 page not found\n"1400 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1401 NarSize: 1601402 References: 1403 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14042026/10/01 08:23:54 OK 20260905000000_add_claims.sql (5.61ms)14052026/10/01 08:23:54 INFO Vacuumed table table=pending_closures1406 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1407 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1408 {"version":1,"root":{"type":"regular","size":44}}14092026/10/01 08:23:54 INFO Vacuumed table table=pending_objects14102026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads14112026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (3.44ms)14122026/10/01 08:23:54 INFO Vacuumed table table=closures14132026/10/01 08:23:54 INFO Upload complete. (90ms)14142026/10/01 08:23:54 OK 20241026095416_initial_model.sql (10.62ms)14152026/10/01 08:23:54 INFO Vacuumed table table=objects1416--- PASS: TestNARDeduplicationMetadataUploadBug (0.96s)1417=== CONT TestUploadHandlersRejectInvalidKeys1418=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1419=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1420=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1421=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1422=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1423=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1424=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1425=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1426=== CONT TestIsValidUploadKey1427=== RUN TestIsValidUploadKey/narinfo1428=== PAUSE TestIsValidUploadKey/narinfo1429=== RUN TestIsValidUploadKey/nar_zst1430=== PAUSE TestIsValidUploadKey/nar_zst1431=== RUN TestIsValidUploadKey/nar_xz1432=== PAUSE TestIsValidUploadKey/nar_xz1433=== RUN TestIsValidUploadKey/nar_plain1434=== PAUSE TestIsValidUploadKey/nar_plain1435=== RUN TestIsValidUploadKey/listing1436=== PAUSE TestIsValidUploadKey/listing1437=== RUN TestIsValidUploadKey/build_log1438=== PAUSE TestIsValidUploadKey/build_log1439=== RUN TestIsValidUploadKey/build_log_home-manager_file1440=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1441=== RUN TestIsValidUploadKey/build_log_plus_in_name1442=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1443=== RUN TestIsValidUploadKey/build_log_question_mark1444=== PAUSE TestIsValidUploadKey/build_log_question_mark14452026/10/01 08:23:54 OK 20241026095416_initial_model.sql (7.26ms)1446=== RUN TestIsValidUploadKey/build_log_equals1447=== PAUSE TestIsValidUploadKey/build_log_equals1448=== RUN TestIsValidUploadKey/realisation1449=== PAUSE TestIsValidUploadKey/realisation1450=== RUN TestIsValidUploadKey/realisation_plus_in_output1451=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1452=== RUN TestIsValidUploadKey/nix-cache-info1453=== PAUSE TestIsValidUploadKey/nix-cache-info1454=== RUN TestIsValidUploadKey/index.html1455=== PAUSE TestIsValidUploadKey/index.html1456=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1457=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1458=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1459=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1460=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1461=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1462=== RUN TestIsValidUploadKey/traversal1463=== PAUSE TestIsValidUploadKey/traversal1464=== RUN TestIsValidUploadKey/traversal_nar1465=== PAUSE TestIsValidUploadKey/traversal_nar1466=== RUN TestIsValidUploadKey/absolute1467=== PAUSE TestIsValidUploadKey/absolute1468=== RUN TestIsValidUploadKey/empty_key14692026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.89ms)14702026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200001471=== PAUSE TestIsValidUploadKey/empty_key1472=== RUN TestIsValidUploadKey/unknown_type1473=== PAUSE TestIsValidUploadKey/unknown_type1474=== CONT TestProxyWriteTimeout1475=== RUN TestProxyWriteTimeout/narinfo1476=== PAUSE TestProxyWriteTimeout/narinfo1477=== RUN TestProxyWriteTimeout/1_GiB_nar1478=== PAUSE TestProxyWriteTimeout/1_GiB_nar1479=== RUN TestProxyWriteTimeout/10_GiB_nar1480=== PAUSE TestProxyWriteTimeout/10_GiB_nar1481=== RUN TestProxyWriteTimeout/unknown_size1482=== PAUSE TestProxyWriteTimeout/unknown_size1483=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14842026/10/01 08:23:54 INFO lead: acquired remote=192.0.2.1:123414852026/10/01 08:23:54 INFO lead: released remote=192.0.2.1:12341486--- PASS: TestLeadEndsOnShutdown (0.95s)1487=== CONT TestSkippedUploadsHandler14882026/10/01 08:23:54 INFO Client skipped oversized paths paths=3 nar_bytes=500000000014892026/10/01 08:23:54 INFO Aborted multipart uploads count=014902026/10/01 08:23:54 WARN Force mode enabled - objects will be deleted immediately without grace period14912026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.46ms)14922026/10/01 08:23:54 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=014932026-10-01 08:23:54.526 UTC [900] ERROR: relation "goose_db_version" does not exist at character 3614942026-10-01 08:23:54.526 UTC [900] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14952026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)14962026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.34ms)1497=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart14982026/10/01 08:23:54 INFO Vacuumed table table=pending_closures1499=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1500=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1501=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1502=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1503=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure15042026/10/01 08:23:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1505=== CONT TestParseSize1506--- PASS: TestSkippedUploadsHandler (0.08s)1507--- PASS: TestParseSize (0.00s)15082026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (81.98ms)1509=== CONT TestService_Rustfstest15102026/10/01 08:23:54 OK 20251218171726_add_pins.sql (82.61ms)1511=== CONT TestPresignedUploadRegisteredBeforeCommit15122026/10/01 08:23:54 OK 3_commit_push.sql (81.84ms)15132026/10/01 08:23:54 goose: up to current file version: 315142026/10/01 08:23:54 INFO Vacuumed table table=pending_objects15152026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads15162026/10/01 08:23:54 INFO Vacuumed table table=closures15172026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)15182026/10/01 08:23:54 OK 20251218171726_add_pins.sql (4.54ms)15192026/10/01 08:23:54 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst15202026-10-01 08:23:54.614 UTC [920] ERROR: relation "goose_db_version" does not exist at character 3615212026-10-01 08:23:54.614 UTC [920] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1522--- PASS: TestCompleteMultipartUnregistered (1.06s)1523=== CONT TestCompletedNarNotReofferedAcrossClosures15242026/10/01 08:23:54 INFO Vacuumed table table=objects1525--- PASS: TestPushDedupSurvivesConcurrentGC (1.05s)1526=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15272026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.61ms)15282026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.49ms)15292026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.21ms)15302026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.34ms)15312026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000015322026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.29ms)15332026/10/01 08:23:54 OK 20260905000000_add_claims.sql (5.41ms)15342026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.18ms)15352026/10/01 08:23:54 OK 3_commit_push.sql (1.19ms)15362026/10/01 08:23:54 goose: up to current file version: 315372026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (3.72ms)15382026/10/01 08:23:54 OK 20241026095416_initial_model.sql (18.38ms)15392026/10/01 08:23:54 OK 20241026095416_initial_model.sql (12.64ms)15402026/10/01 08:23:54 INFO Received push request method=POST path=/api/pushes15412026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (23.63ms)15422026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000015432026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (19.28ms)15442026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (19.06ms)15452026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures15462026/10/01 08:23:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15472026/10/01 08:23:54 INFO Uploading id2g16bvw7588gv81snlv7wcyi3m2afp-unpinned-file.txt (128B)15482026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.87ms)15492026/10/01 08:23:54 OK 20251218171726_add_pins.sql (4.67ms)15502026/10/01 08:23:54 OK 2_object_stats_trigger.sql (3.04ms)15512026/10/01 08:23:54 OK 20251218171726_add_pins.sql (5.99ms)15522026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15532026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15542026/10/01 08:23:54 INFO Signed narinfos id=2 count=115552026/10/01 08:23:54 WARN Failed to register uploaded object key=id2g16bvw7588gv81snlv7wcyi3m2afp.ls error="server returned 404: 404 page not found\n"15562026/10/01 08:23:54 INFO Uploading 1 narinfos15572026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)15582026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)15592026/10/01 08:23:54 OK 3_commit_push.sql (2.04ms)15602026/10/01 08:23:54 OK 20260905000000_add_claims.sql (4.05ms)15612026/10/01 08:23:54 INFO Received complete push request method=POST path=/api/pushes/2/complete15622026/10/01 08:23:54 WARN Failed to register uploaded object key=id2g16bvw7588gv81snlv7wcyi3m2afp.narinfo error="server returned 404: 404 page not found\n"15632026/10/01 08:23:54 goose: up to current file version: 315642026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.65ms)15652026/10/01 08:23:54 INFO Upload complete. (63ms)15662026/10/01 08:23:54 OK 20260905000000_add_claims.sql (5.43ms)15672026/10/01 08:23:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15682026/10/01 08:23:54 WARN Refused reserved pin name=worker-x86_64-linux15692026/10/01 08:23:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15702026/10/01 08:23:54 INFO Received create pin request method=POST path=/api/pins/my-app15712026/10/01 08:23:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15722026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (4.71ms)15732026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (4.68ms)15742026/10/01 08:23:54 goose: successfully migrated database to version: 202609231200001575--- PASS: TestCreatePin_ReservedPins (1.12s)1576=== CONT TestPush_SignsNarinfosOfItsPendingObjects15772026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.81ms)15782026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (4.63ms)15792026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000015802026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.67ms)15812026/10/01 08:23:54 OK 3_commit_push.sql (1.75ms)15822026/10/01 08:23:54 goose: up to current file version: 315832026/10/01 08:23:54 OK 1_commit_pending_closure.sql (4.04ms)15842026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.25ms)15852026/10/01 08:23:54 OK 3_commit_push.sql (2.26ms)15862026/10/01 08:23:54 goose: up to current file version: 315872026/10/01 08:23:54 INFO lead: acquired remote=192.0.2.1:123415882026/10/01 08:23:54 INFO Received create pin request method=POST path=/api/pins/myapp15892026/10/01 08:23:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3304320903/001/store/2mv27b4gwhyxm6c2cxn44k9b313hwjma-pinned-file.txt narinfo_key=2mv27b4gwhyxm6c2cxn44k9b313hwjma.narinfo15902026/10/01 08:23:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures15912026/10/01 08:23:54 INFO Garbage collection started15922026/10/01 08:23:54 INFO Aborted multipart uploads count=01593--- PASS: TestGCBugBareHashReferences (1.16s)1594=== CONT TestService_AuthMiddleware_OIDC15952026/10/01 08:23:54 WARN Force mode enabled - objects will be deleted immediately without grace period15962026-10-01 08:23:54.732 UTC [969] ERROR: relation "goose_db_version" does not exist at character 3615972026-10-01 08:23:54.732 UTC [969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15982026-10-01 08:23:54.733 UTC [970] ERROR: relation "goose_db_version" does not exist at character 3615992026-10-01 08:23:54.733 UTC [970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16002026-10-01 08:23:54.733 UTC [971] ERROR: relation "goose_db_version" does not exist at character 3616012026-10-01 08:23:54.733 UTC [971] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16022026-10-01 08:23:54.735 UTC [972] ERROR: relation "goose_db_version" does not exist at character 3616032026-10-01 08:23:54.735 UTC [972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16042026/10/01 08:23:54 OK 20241026095416_initial_model.sql (9.46ms)16052026/10/01 08:23:54 OK 20241026095416_initial_model.sql (12.32ms)16062026/10/01 08:23:54 OK 20241026095416_initial_model.sql (13.19ms)16072026/10/01 08:23:54 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=016082026/10/01 08:23:54 OK 20241026095416_initial_model.sql (12.54ms)16092026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)16102026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)16112026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)16122026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)16132026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.96ms)16142026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.04ms)16152026/10/01 08:23:54 OK 20251218171726_add_pins.sql (3.2ms)16162026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.99ms)16172026/10/01 08:23:54 INFO Vacuumed table table=pending_closures16182026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)16192026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)16202026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)16212026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3ms)16222026/10/01 08:23:54 INFO Vacuumed table table=pending_objects16232026/10/01 08:23:54 INFO Vacuumed table table=multipart_uploads16242026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.85ms)16252026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.73ms)16262026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.88ms)16272026/10/01 08:23:54 OK 20260905000000_add_claims.sql (2.36ms)16282026/10/01 08:23:54 INFO Vacuumed table table=closures16292026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (1.52ms)16302026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (1.59ms)16312026/10/01 08:23:54 INFO Vacuumed table table=objects16322026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.12ms)16332026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000016342026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.02ms)16352026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (1.79ms)16362026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.02ms)16372026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000016382026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.15ms)16392026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000016402026/10/01 08:23:54 OK 1_commit_pending_closure.sql (1.56ms)16412026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.45ms)16422026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000016432026/10/01 08:23:54 OK 1_commit_pending_closure.sql (1.48ms)16442026/10/01 08:23:54 OK 2_object_stats_trigger.sql (749.78µs)16452026/10/01 08:23:54 OK 1_commit_pending_closure.sql (1.51ms)16462026/10/01 08:23:54 OK 2_object_stats_trigger.sql (794.42µs)16472026/10/01 08:23:54 OK 3_commit_push.sql (862.73µs)16482026/10/01 08:23:54 goose: up to current file version: 316492026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.1ms)16502026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.21ms)16512026/10/01 08:23:54 OK 3_commit_push.sql (1.3ms)16522026/10/01 08:23:54 goose: up to current file version: 316532026/10/01 08:23:54 OK 3_commit_push.sql (775.37µs)16542026/10/01 08:23:54 goose: up to current file version: 316552026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.04ms)16562026/10/01 08:23:54 OK 3_commit_push.sql (605.93µs)16572026/10/01 08:23:54 goose: up to current file version: 316582026-10-01 08:23:54.779 UTC [991] ERROR: relation "goose_db_version" does not exist at character 3616592026-10-01 08:23:54.779 UTC [991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1660--- PASS: TestService_healthCheckHandler (0.61s)1661=== CONT TestCacheConfigHandler1662=== RUN TestCacheConfigHandler/full_config,_no_issuer1663=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1664=== RUN TestCacheConfigHandler/no_cache_url_configured1665=== PAUSE TestCacheConfigHandler/no_cache_url_configured1666=== RUN TestCacheConfigHandler/no_signing_keys1667=== PAUSE TestCacheConfigHandler/no_signing_keys1668=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1669=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1670=== CONT TestService_ReadScope_PublicByDefault16712026/10/01 08:23:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33637/oidc16722026/10/01 08:23:54 OK 20241026095416_initial_model.sql (7.12ms)16732026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)16742026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.85ms)16752026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)16762026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.16ms)16772026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (3.52ms)16782026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.75ms)16792026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000016802026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.55ms)16812026/10/01 08:23:54 OK 2_object_stats_trigger.sql (2.08ms)16822026/10/01 08:23:54 OK 3_commit_push.sql (1.97ms)16832026/10/01 08:23:54 goose: up to current file version: 31684--- PASS: TestCacheStatsHandler (0.65s)1685=== CONT TestService_RequireScope_OIDC16862026/10/01 08:23:54 INFO lead: released remote=192.0.2.1:12341687--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.31s)1688=== CONT TestGetExistingObjectsLocksRows16892026-10-01 08:23:54.872 UTC [1078] ERROR: relation "goose_db_version" does not exist at character 3616902026-10-01 08:23:54.872 UTC [1078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16912026-10-01 08:23:54.876 UTC [1100] ERROR: relation "goose_db_version" does not exist at character 3616922026-10-01 08:23:54.876 UTC [1100] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16932026/10/01 08:23:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41497/oidc16942026/10/01 08:23:54 OK 20241026095416_initial_model.sql (8.38ms)16952026/10/01 08:23:54 OK 20241026095416_initial_model.sql (13.62ms)16962026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)16972026/10/01 08:23:54 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)16982026/10/01 08:23:54 OK 20251218171726_add_pins.sql (2.7ms)16992026/10/01 08:23:54 OK 20251218171726_add_pins.sql (5.12ms)17002026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)17012026/10/01 08:23:54 INFO lead: acquired remote=192.0.2.1:123417022026/10/01 08:23:54 OK 20260905000000_add_claims.sql (3.09ms)17032026/10/01 08:23:54 OK 20260628120000_add_object_size_and_stats.sql (5.7ms)17042026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (2.55ms)17052026/10/01 08:23:54 INFO lead: released remote=192.0.2.1:12341706--- PASS: TestLeadElectsOneAndHandsOver (0.93s)1707=== CONT TestGCTaskStore_ConflictDifferentParams1708--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1709=== CONT TestGCTaskStore_DeduplicateSameParams1710--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1711=== CONT TestGCTaskStore_StartNew1712--- PASS: TestGCTaskStore_StartNew (0.00s)1713=== CONT TestSweepSkipsRowsLockedByPush17142026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (1.91ms)17152026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000017162026/10/01 08:23:54 OK 20260905000000_add_claims.sql (4.21ms)17172026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.27ms)17182026/10/01 08:23:54 OK 20260920000000_drop_claims.sql (13.12ms)17192026/10/01 08:23:54 OK 2_object_stats_trigger.sql (13.33ms)17202026/10/01 08:23:54 OK 20260923120000_add_pushes.sql (2.42ms)17212026/10/01 08:23:54 goose: successfully migrated database to version: 2026092312000017222026/10/01 08:23:54 OK 3_commit_push.sql (2.1ms)1723=== NAME TestClientMultipleUploads17242026/10/01 08:23:54 goose: up to current file version: 31725 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2726118663/001/store/l31c2549iayl2y0fky213968bbnb6p76-test-file-0.txt17262026/10/01 08:23:54 OK 1_commit_pending_closure.sql (2.14ms)17272026/10/01 08:23:54 OK 2_object_stats_trigger.sql (1.71ms)17282026/10/01 08:23:54 OK 3_commit_push.sql (1.14ms)17292026/10/01 08:23:54 goose: up to current file version: 317302026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures17312026/10/01 08:23:54 INFO Received push request method=POST path=/api/pushes17322026/10/01 08:23:54 INFO Received uploads request method=POST path=/api/pending_closures1733=== RUN TestPush_RejectsBadRequests/no_roots1734=== PAUSE TestPush_RejectsBadRequests/no_roots1735=== RUN TestPush_RejectsBadRequests/no_objects1736=== PAUSE TestPush_RejectsBadRequests/no_objects1737=== NAME TestClientIntegration1738 client_integration_test.go:286: Created store path: /build/TestClientIntegration1918417331/002/store/pl93m5q8cvb5p752y67v2aipm23m13gh-test-file.txt1739=== RUN TestPush_RejectsBadRequests/bad_root1740=== PAUSE TestPush_RejectsBadRequests/bad_root1741=== RUN TestPush_RejectsBadRequests/root_not_in_objects1742=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1743=== CONT TestRegisterCompletedObjectNeedsPendingRow17442026/10/01 08:23:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17452026/10/01 08:23:54 INFO Uploading sr1w510jj6b0gs3qn7ss14pjfdsyqczk-b (216B)17462026/10/01 08:23:54 INFO Uploading i1midl9hzbd1h6v7fdiysldmds2khqxk-shared-dep (136B)1747=== NAME TestClientWithDependencies1748 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3465475891/001/store/fnx3lj5p818cb73sl3q21zviglbscy28-test-script17492026/10/01 08:23:54 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17502026/10/01 08:23:54 INFO Uploading q9g95y29365ppx2qd4l855q2p0jsvx8k-shared-dep (136B)17512026/10/01 08:23:54 INFO Uploading fqzzyg0lpp81ppdr7rd687r126yfw7az-b (216B)17522026/10/01 08:23:54 WARN Failed to register uploaded object key=sr1w510jj6b0gs3qn7ss14pjfdsyqczk.ls error="server returned 404: 404 page not found\n"17532026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/17c9gyx37rcis64r8zlbyz87nlc6nsjv9zw5l65h2crwdwzb33xf.nar.zst error="server returned 404: 404 page not found\n"17542026/10/01 08:23:54 WARN Failed to register uploaded object key=i1midl9hzbd1h6v7fdiysldmds2khqxk.ls error="server returned 404: 404 page not found\n"17552026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17562026/10/01 08:23:54 WARN Failed to register uploaded object key=ig5j1yz5jk7998rcakfn9dmx81jfxivn.ls error="server returned 404: 404 page not found\n"17572026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17582026/10/01 08:23:54 INFO Signed narinfos id=1 count=217592026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17602026/10/01 08:23:54 INFO Signed narinfos id=2 count=217612026/10/01 08:23:54 INFO Uploading 4 narinfos17622026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17632026/10/01 08:23:54 WARN Failed to register uploaded object key=nar/1c0rw0wasdjx9kavpaxxfhcvxs8pm0xzzx3iznl1n5mw5a205j5b.nar.zst error="server returned 404: 404 page not found\n"17642026/10/01 08:23:54 WARN Failed to register uploaded object key=29172whrhil3g57g67x9v93s2dgich10.ls error="server returned 404: 404 page not found\n"17652026/10/01 08:23:54 WARN Failed to register uploaded object key=fqzzyg0lpp81ppdr7rd687r126yfw7az.ls error="server returned 404: 404 page not found\n"17662026/10/01 08:23:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17672026/10/01 08:23:54 WARN Failed to register uploaded object key=q9g95y29365ppx2qd4l855q2p0jsvx8k.ls error="server returned 404: 404 page not found\n"17682026/10/01 08:23:54 INFO Signed narinfos id=1 count=317692026/10/01 08:23:54 INFO Uploading 3 narinfos17702026-10-01 08:23:54.965 UTC [1322] ERROR: relation "goose_db_version" does not exist at character 3617712026-10-01 08:23:54.965 UTC [1322] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17722026/10/01 08:23:54 WARN Failed to register uploaded object key=sr1w510jj6b0gs3qn7ss14pjfdsyqczk.narinfo error="server returned 404: 404 page not found\n"17732026/10/01 08:23:54 WARN Failed to register uploaded object key=i1midl9hzbd1h6v7fdiysldmds2khqxk.narinfo error="server returned 404: 404 page not found\n"17742026/10/01 08:23:54 WARN Failed to register uploaded object key=ig5j1yz5jk7998rcakfn9dmx81jfxivn.narinfo error="server returned 404: 404 page not found\n"17752026/10/01 08:23:54 WARN Failed to register uploaded object key=29172whrhil3g57g67x9v93s2dgich10.narinfo error="server returned 404: 404 page not found\n"17762026/10/01 08:23:54 WARN Failed to register uploaded object key=fqzzyg0lpp81ppdr7rd687r126yfw7az.narinfo error="server returned 404: 404 page not found\n"17772026/10/01 08:23:54 INFO Received complete push request method=POST path=/api/pushes/1/complete17782026/10/01 08:23:54 WARN Failed to register uploaded object key=q9g95y29365ppx2qd4l855q2p0jsvx8k.narinfo error="server returned 404: 404 page not found\n"17792026/10/01 08:23:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17802026/10/01 08:23:54 WARN Failed to register uploaded object key=i1midl9hzbd1h6v7fdiysldmds2khqxk.narinfo error="server returned 404: 404 page not found\n"1781=== NAME TestClientMultipleUploads1782 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2726118663/001/store/dip78mgblwymspzkyhy72mcvj8rd17gk-test-file-1.txt17832026/10/01 08:23:54 INFO Completed upload id=217842026/10/01 08:23:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17852026/10/01 08:23:54 INFO Upload complete. (80ms)1786=== NAME TestClientPushesUseOnePush1787 client_pushes_test.go:97: Retrieved narinfo from S3:1788 StorePath: /build/TestClientPushesUseOnePush4037808794/001/store/q9g95y29365ppx2qd4l855q2p0jsvx8k-shared-dep1789 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1790 Compression: zstd1791 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821792 NarSize: 1361793 References: 1794 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1795 client_pushes_test.go:97: Retrieved narinfo from S3:1796 StorePath: /build/TestClientPushesUseOnePush4037808794/001/store/29172whrhil3g57g67x9v93s2dgich10-a1797 URL: nar/1c0rw0wasdjx9kavpaxxfhcvxs8pm0xzzx3iznl1n5mw5a205j5b.nar.zst1798 Compression: zstd1799 NarHash: sha256:1c0rw0wasdjx9kavpaxxfhcvxs8pm0xzzx3iznl1n5mw5a205j5b1800 NarSize: 2161801 References: /build/TestClientPushesUseOnePush4037808794/001/store/q9g95y29365ppx2qd4l855q2p0jsvx8k-shared-dep1802 CA: text:sha256:0mrks968ri8a2rjlfrwxmfib31jlm09ibjim50kqp0yzigmpr7f71803 client_pushes_test.go:97: Retrieved narinfo from S3:1804 StorePath: /build/TestClientPushesUseOnePush4037808794/001/store/fqzzyg0lpp81ppdr7rd687r126yfw7az-b1805 URL: nar/1c0rw0wasdjx9kavpaxxfhcvxs8pm0xzzx3iznl1n5mw5a205j5b.nar.zst1806 Compression: zstd1807 NarHash: sha256:1c0rw0wasdjx9kavpaxxfhcvxs8pm0xzzx3iznl1n5mw5a205j5b1808 NarSize: 2161809 References: /build/TestClientPushesUseOnePush4037808794/001/store/q9g95y29365ppx2qd4l855q2p0jsvx8k-shared-dep1810 CA: text:sha256:0mrks968ri8a2rjlfrwxmfib31jlm09ibjim50kqp0yzigmpr7f718112026/10/01 08:23:54 OK 20241026095416_initial_model.sql (20.69ms)1812=== NAME TestClientWithDependencies18132026/10/01 08:23:54 INFO Completed upload id=11814 client_integration_test.go:615: Found 1 dependencies (including self)18152026/10/01 08:23:54 INFO Upload complete. (99ms)18162026-10-01 08:23:54.998 UTC [1359] ERROR: relation "goose_db_version" does not exist at character 3618172026-10-01 08:23:54.998 UTC [1359] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1818=== NAME TestClientFallsBackToClosures1819 client_pushes_test.go:112: Retrieved narinfo from S3:1820 StorePath: /build/TestClientFallsBackToClosures1516916437/001/store/i1midl9hzbd1h6v7fdiysldmds2khqxk-shared-dep1821 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1822 Compression: zstd1823 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821824 NarSize: 1361825 References: 1826 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1827 client_pushes_test.go:112: Retrieved narinfo from S3:1828 StorePath: /build/TestClientFallsBackToClosures1516916437/001/store/ig5j1yz5jk7998rcakfn9dmx81jfxivn-a1829 URL: nar/17c9gyx37rcis64r8zlbyz87nlc6nsjv9zw5l65h2crwdwzb33xf.nar.zst1830 Compression: zstd1831 NarHash: sha256:17c9gyx37rcis64r8zlbyz87nlc6nsjv9zw5l65h2crwdwzb33xf1832 NarSize: 2161833 References: /build/TestClientFallsBackToClosures1516916437/001/store/i1midl9hzbd1h6v7fdiysldmds2khqxk-shared-dep1834 CA: text:sha256:1830abws6lcx24gxvnaiv3h0nhxy4wx27iy74n4hb7j0kq96ddzv18352026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes1836--- PASS: TestClientPushesUseOnePush (0.91s)18372026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (7.21ms)1838=== CONT TestReadProxyRootRedirectsToIndexHTML1839=== NAME TestClientFallsBackToClosures1840 client_pushes_test.go:112: Retrieved narinfo from S3:1841 StorePath: /build/TestClientFallsBackToClosures1516916437/001/store/sr1w510jj6b0gs3qn7ss14pjfdsyqczk-b1842 URL: nar/17c9gyx37rcis64r8zlbyz87nlc6nsjv9zw5l65h2crwdwzb33xf.nar.zst1843 Compression: zstd1844 NarHash: sha256:17c9gyx37rcis64r8zlbyz87nlc6nsjv9zw5l65h2crwdwzb33xf1845 NarSize: 2161846 References: /build/TestClientFallsBackToClosures1516916437/001/store/i1midl9hzbd1h6v7fdiysldmds2khqxk-shared-dep1847 CA: text:sha256:1830abws6lcx24gxvnaiv3h0nhxy4wx27iy74n4hb7j0kq96ddzv1848--- PASS: TestClientFallsBackToClosures (1.04s)1849=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit18502026-10-01 08:23:55.025 UTC [1400] ERROR: relation "goose_db_version" does not exist at character 3618512026-10-01 08:23:55.025 UTC [1400] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18522026/10/01 08:23:55 OK 20251218171726_add_pins.sql (21.55ms)18532026/10/01 08:23:55 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18542026/10/01 08:23:55 INFO Uploading fz9l0dxj2s2v7w5sasd2nzr9qxbi5m7v-shared-dep (136B)18552026/10/01 08:23:55 INFO Uploading jkgf9i5nski0sixn2yypqpv08ngfvwhy-top (224B)18562026/10/01 08:23:55 OK 20241026095416_initial_model.sql (26.07ms)18572026/10/01 08:23:55 WARN Failed to register uploaded object key=fz9l0dxj2s2v7w5sasd2nzr9qxbi5m7v.ls error="server returned 404: 404 page not found\n"18582026/10/01 08:23:55 WARN Failed to register uploaded object key=jkgf9i5nski0sixn2yypqpv08ngfvwhy.ls error="server returned 404: 404 page not found\n"18592026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18602026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/0hfbf0dlg8qfsddsbjm9jym73ryb2584n0nhlvrs7fs30q1b7fvd.nar.zst error="server returned 404: 404 page not found\n"18612026/10/01 08:23:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18622026/10/01 08:23:55 INFO Signed narinfos id=1 count=218632026/10/01 08:23:55 INFO Uploading 2 narinfos18642026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (10.02ms)18652026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (3.86ms)18662026/10/01 08:23:55 OK 20260905000000_add_claims.sql (4.35ms)18672026/10/01 08:23:55 WARN Failed to register uploaded object key=jkgf9i5nski0sixn2yypqpv08ngfvwhy.narinfo error="server returned 404: 404 page not found\n"18682026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete18692026/10/01 08:23:55 WARN Failed to register uploaded object key=fz9l0dxj2s2v7w5sasd2nzr9qxbi5m7v.narinfo error="server returned 404: 404 page not found\n"18702026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes18712026/10/01 08:23:55 OK 20251218171726_add_pins.sql (5.46ms)1872=== NAME TestClientMultipleUploads18732026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures1874 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2726118663/001/store/j3nwzm8dyfdh8yhq95y0fafhjj0lsxam-test-file-2.txt18752026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (4.39ms)18762026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.16ms)18772026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)18782026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.91ms)18792026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000018802026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (5.92ms)18812026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.98ms)18822026/10/01 08:23:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18832026/10/01 08:23:55 INFO Uploading pl93m5q8cvb5p752y67v2aipm23m13gh-test-file.txt (152B)18842026/10/01 08:23:55 INFO Upload complete. (96ms)18852026/10/01 08:23:55 OK 1_commit_pending_closure.sql (3.04ms)1886=== NAME TestClientSharedPathCommittedMidPush1887 client_integration_test.go:680: Retrieved narinfo from S3:1888 StorePath: /build/TestClientSharedPathCommittedMidPush2835892188/001/store/fz9l0dxj2s2v7w5sasd2nzr9qxbi5m7v-shared-dep1889 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1890 Compression: zstd1891 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821892 NarSize: 1361893 References: 1894 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18952026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.02ms)18962026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)18972026/10/01 08:23:55 OK 20260905000000_add_claims.sql (5.93ms)1898 client_integration_test.go:680: Retrieved narinfo from S3:1899 StorePath: /build/TestClientSharedPathCommittedMidPush2835892188/001/store/jkgf9i5nski0sixn2yypqpv08ngfvwhy-top1900 URL: nar/0hfbf0dlg8qfsddsbjm9jym73ryb2584n0nhlvrs7fs30q1b7fvd.nar.zst1901 Compression: zstd1902 NarHash: sha256:0hfbf0dlg8qfsddsbjm9jym73ryb2584n0nhlvrs7fs30q1b7fvd1903 NarSize: 2241904 References: /build/TestClientSharedPathCommittedMidPush2835892188/001/store/fz9l0dxj2s2v7w5sasd2nzr9qxbi5m7v-shared-dep1905 CA: text:sha256:01qzij6wibqbnf64n8agrb6x3xcdx70kbhswzznxyxf8x3gvsrlp19062026/10/01 08:23:55 WARN Failed to register uploaded object key=pl93m5q8cvb5p752y67v2aipm23m13gh.ls error="server returned 404: 404 page not found\n"19072026/10/01 08:23:55 OK 3_commit_push.sql (2.06ms)19082026/10/01 08:23:55 goose: up to current file version: 319092026/10/01 08:23:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1910=== NAME TestClientCADerivations19112026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1912 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3862991666/001/store/3x9841mgqa41dq8wb2sv8yly8skyhg7n-ca-test19132026/10/01 08:23:55 INFO Signed narinfos id=1 count=119142026/10/01 08:23:55 INFO Uploading 1 narinfos19152026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete19162026/10/01 08:23:55 WARN Failed to register uploaded object key=pl93m5q8cvb5p752y67v2aipm23m13gh.narinfo error="server returned 404: 404 page not found\n"1917--- PASS: TestClientSharedPathCommittedMidPush (0.87s)1918=== CONT TestPush_CompleteCommitsEveryRoot19192026/10/01 08:23:55 OK 20260905000000_add_claims.sql (12.26ms)19202026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (13.56ms)19212026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (4.45ms)19222026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.66ms)19232026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000019242026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures19252026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures19262026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures19272026/10/01 08:23:55 INFO Upload complete. (87ms)19282026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.02ms)19292026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000019302026/10/01 08:23:55 OK 1_commit_pending_closure.sql (3.45ms)19312026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.16ms)19322026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.57ms)19332026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.27ms)19342026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes19352026/10/01 08:23:55 OK 3_commit_push.sql (2.06ms)19362026/10/01 08:23:55 goose: up to current file version: 319372026-10-01 08:23:55.082 UTC [1492] ERROR: relation "goose_db_version" does not exist at character 3619382026-10-01 08:23:55.082 UTC [1492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19392026/10/01 08:23:55 OK 3_commit_push.sql (1.64ms)19402026/10/01 08:23:55 goose: up to current file version: 31941=== NAME TestClientCADerivations1942 client_ca_test.go:139: Found 1 dependencies (including self)19432026/10/01 08:23:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19442026/10/01 08:23:55 INFO Uploading fnx3lj5p818cb73sl3q21zviglbscy28-test-script (136B)19452026/10/01 08:23:55 WARN Failed to register uploaded object key=fnx3lj5p818cb73sl3q21zviglbscy28.ls error="server returned 404: 404 page not found\n"19462026/10/01 08:23:55 WARN Failed to register uploaded object key=log/m1gs054hb83iglxs7zqc77qpk2vgy3fs-test-script.drv error="server returned 404: 404 page not found\n"19472026/10/01 08:23:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19482026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19492026/10/01 08:23:55 INFO Signed narinfos id=1 count=119502026/10/01 08:23:55 INFO Uploading 1 narinfos19512026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.8ms)19522026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)19532026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete19542026/10/01 08:23:55 WARN Failed to register uploaded object key=fnx3lj5p818cb73sl3q21zviglbscy28.narinfo error="server returned 404: 404 page not found\n"19552026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures19562026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.36ms)19572026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)19582026/10/01 08:23:55 INFO All 1 paths already cached1959=== NAME TestClientIntegration1960 client_integration_test.go:312: Retrieved narinfo from S3:1961 StorePath: /build/TestClientIntegration1918417331/002/store/pl93m5q8cvb5p752y67v2aipm23m13gh-test-file.txt19622026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.32ms)1963 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1964 Compression: zstd1965 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11966 NarSize: 1521967 References: 1968 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119692026/10/01 08:23:55 INFO Upload complete. (76ms)19702026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.75ms)1971 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1972 client_integration_test.go:313: Decompressed .ls content (64 bytes):1973 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1974 client_integration_test.go:316: Testing garbage collection...1975=== NAME TestClientWithDependencies1976 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3465475891/001/store) requires matching store prefix19772026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.31ms)19782026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000019792026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.48ms)19802026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.33ms)1981--- PASS: TestClientWithDependencies (0.88s)1982=== CONT TestRedundantMultipartUpload19832026/10/01 08:23:55 OK 3_commit_push.sql (1.19ms)19842026/10/01 08:23:55 goose: up to current file version: 319852026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes19862026/10/01 08:23:55 INFO Received cleanup request method=DELETE path=/api/pending_closures19872026-10-01 08:23:55.141 UTC [1567] ERROR: relation "goose_db_version" does not exist at character 3619882026-10-01 08:23:55.141 UTC [1567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19892026/10/01 08:23:55 INFO Aborted multipart uploads count=019902026/10/01 08:23:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19912026/10/01 08:23:55 INFO Uploading j3nwzm8dyfdh8yhq95y0fafhjj0lsxam-test-file-2.txt (160B)19922026/10/01 08:23:55 INFO Uploading dip78mgblwymspzkyhy72mcvj8rd17gk-test-file-1.txt (160B)19932026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures19942026/10/01 08:23:55 INFO Uploading l31c2549iayl2y0fky213968bbnb6p76-test-file-0.txt (160B)19952026/10/01 08:23:55 WARN Failed to register uploaded object key=j3nwzm8dyfdh8yhq95y0fafhjj0lsxam.ls error="server returned 404: 404 page not found\n"19962026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19972026/10/01 08:23:55 WARN Failed to register uploaded object key=dip78mgblwymspzkyhy72mcvj8rd17gk.ls error="server returned 404: 404 page not found\n"19982026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19992026/10/01 08:23:55 WARN Failed to register uploaded object key=l31c2549iayl2y0fky213968bbnb6p76.ls error="server returned 404: 404 page not found\n"20002026/10/01 08:23:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20012026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20022026/10/01 08:23:55 INFO Signed narinfos id=1 count=320032026/10/01 08:23:55 INFO Uploading 3 narinfos20042026/10/01 08:23:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures20052026/10/01 08:23:55 INFO Garbage collection started20062026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.47ms)20072026/10/01 08:23:55 WARN Failed to register uploaded object key=dip78mgblwymspzkyhy72mcvj8rd17gk.narinfo error="server returned 404: 404 page not found\n"20082026/10/01 08:23:55 WARN Failed to register uploaded object key=j3nwzm8dyfdh8yhq95y0fafhjj0lsxam.narinfo error="server returned 404: 404 page not found\n"20092026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete20102026/10/01 08:23:55 WARN Failed to register uploaded object key=l31c2549iayl2y0fky213968bbnb6p76.narinfo error="server returned 404: 404 page not found\n"20112026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)20122026/10/01 08:23:55 INFO Received cleanup request method=DELETE path=/api/pending_closures20132026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.49ms)20142026/10/01 08:23:55 INFO Aborted multipart uploads count=120152026-10-01 08:23:55.163 UTC [1586] ERROR: relation "goose_db_version" does not exist at character 3620162026-10-01 08:23:55.163 UTC [1586] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20172026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)20182026/10/01 08:23:55 INFO Aborted multipart uploads count=020192026/10/01 08:23:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20202026-10-01 08:23:55.167 UTC [900] ERROR: Closure does not exist: id=120212026-10-01 08:23:55.167 UTC [900] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE20222026-10-01 08:23:55.167 UTC [900] STATEMENT: -- name: CommitPendingClosure :exec2023 SELECT commit_pending_closure($1::bigint)2024 2025--- PASS: TestService_cleanupPendingClosuresHandler (0.76s)2026=== CONT TestPush_OverlappingRootsStoreOneRowPerKey20272026/10/01 08:23:55 OK 20260905000000_add_claims.sql (2.47ms)20282026/10/01 08:23:55 WARN Force mode enabled - objects will be deleted immediately without grace period2029--- PASS: TestService_Rustfstest (0.56s)2030=== CONT TestReadRedirectUsesPublicS3URL20312026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.26ms)20322026/10/01 08:23:55 INFO Upload complete. (90ms)2033=== NAME TestClientMultipleUploads2034 client_integration_test.go:369: Uploaded 3 paths in 127.383831ms20352026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (1.94ms)20362026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000020372026-10-01 08:23:55.173 UTC [1590] ERROR: relation "goose_db_version" does not exist at character 3620382026-10-01 08:23:55.173 UTC [1590] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20392026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.94ms)20402026/10/01 08:23:55 OK 20241026095416_initial_model.sql (8.46ms)20412026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.2ms)20422026/10/01 08:23:55 OK 3_commit_push.sql (1.08ms)20432026/10/01 08:23:55 goose: up to current file version: 320442026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)20452026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.83ms)20462026/10/01 08:23:55 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=02047--- PASS: TestClientMultipleUploads (0.93s)20482026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)2049=== CONT TestReadProxyRangeRequest20502026/10/01 08:23:55 INFO Vacuumed table table=pending_closures20512026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures20522026/10/01 08:23:55 OK 20241026095416_initial_model.sql (18.15ms)20532026/10/01 08:23:55 OK 20260905000000_add_claims.sql (13.66ms)20542026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (4.75ms)20552026/10/01 08:23:55 INFO Vacuumed table table=pending_objects20562026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20572026/10/01 08:23:55 INFO Vacuumed table table=multipart_uploads20582026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.56ms)20592026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.41ms)20602026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.05ms)20612026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000020622026/10/01 08:23:55 INFO Vacuumed table table=closures20632026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)20642026/10/01 08:23:55 OK 1_commit_pending_closure.sql (4.37ms)20652026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes20662026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.95ms)20672026/10/01 08:23:55 INFO Vacuumed table table=objects20682026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.53ms)20692026/10/01 08:23:55 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20702026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures20712026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.97ms)20722026/10/01 08:23:55 OK 3_commit_push.sql (2.05ms)20732026/10/01 08:23:55 goose: up to current file version: 320742026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures20752026/10/01 08:23:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20762026/10/01 08:23:55 INFO Uploading 3x9841mgqa41dq8wb2sv8yly8skyhg7n-ca-test (144B)20772026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.5ms)20782026/10/01 08:23:55 goose: successfully migrated database to version: 202609231200002079--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.61s)2080=== CONT TestReadProxy40420812026/10/01 08:23:55 OK 1_commit_pending_closure.sql (3.17ms)20822026/10/01 08:23:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20832026/10/01 08:23:55 WARN Failed to register uploaded object key=log/x2n2pq5x0chy2j8ilnwzclg5cdvx55p7-ca-test.drv error="server returned 404: 404 page not found\n"20842026/10/01 08:23:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20852026/10/01 08:23:55 WARN Failed to register uploaded object key=3x9841mgqa41dq8wb2sv8yly8skyhg7n.ls error="server returned 404: 404 page not found\n"20862026/10/01 08:23:55 INFO Signed narinfos id=1 count=120872026/10/01 08:23:55 INFO Uploading 1 narinfos20882026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.78ms)20892026/10/01 08:23:55 OK 3_commit_push.sql (1.9ms)20902026/10/01 08:23:55 goose: up to current file version: 320912026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete20922026/10/01 08:23:55 WARN Failed to register uploaded object key=3x9841mgqa41dq8wb2sv8yly8skyhg7n.narinfo error="server returned 404: 404 page not found\n"20932026/10/01 08:23:55 INFO Upload complete. (99ms)2094=== NAME TestClientCADerivations2095 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3862991666/001/store/3x9841mgqa41dq8wb2sv8yly8skyhg7n-ca-test2096 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2097 Compression: zstd2098 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2099 NarSize: 1442100 References: 2101 Deriver: /build/TestClientCADerivations3862991666/001/store/x2n2pq5x0chy2j8ilnwzclg5cdvx55p7-ca-test.drv2102 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2103 client_ca_test.go:185: Checking for realisation files in S3...2104 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2105 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21062026-10-01 08:23:55.238 UTC [1633] ERROR: relation "goose_db_version" does not exist at character 3621072026-10-01 08:23:55.238 UTC [1633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21082026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures21092026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.98ms)21102026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21112026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)21122026/10/01 08:23:55 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjQzMWM4YWEtODQ4NC00ZDhlLThjMTMtYWRmMWJmZjJiM2JkLjQyMmU3ZDY1LWY4NjUtNDljYi04YzVmLTFlNzJlZjAyNWU2Y3gxNzkwODQzMDM1MjMxODM4MjM321132026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.09ms)21142026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)21152026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes21162026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.08ms)21172026/10/01 08:23:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjQzMWM4YWEtODQ4NC00ZDhlLThjMTMtYWRmMWJmZjJiM2JkLjQyMmU3ZDY1LWY4NjUtNDljYi04YzVmLTFlNzJlZjAyNWU2Y3gxNzkwODQzMDM1MjMxODM4MjM3 parts=12118--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.65s)2119=== CONT TestReadRedirectKeepsNarinfoProxied21202026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.52ms)21212026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (9.93ms)21222026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000021232026-10-01 08:23:55.281 UTC [1656] ERROR: relation "goose_db_version" does not exist at character 3621242026-10-01 08:23:55.281 UTC [1656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21252026-10-01 08:23:55.282 UTC [1654] ERROR: relation "goose_db_version" does not exist at character 3621262026-10-01 08:23:55.282 UTC [1654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21272026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.93ms)21282026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.82ms)21292026/10/01 08:23:55 OK 3_commit_push.sql (1.53ms)21302026/10/01 08:23:55 goose: up to current file version: 321312026/10/01 08:23:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2132=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2133=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token21342026/10/01 08:23:55 INFO Signed narinfos id=1 count=12135=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2136=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2137=== CONT TestReadProxyConditionalGet2138=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2139--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.61s)2140=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2141=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2142=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2143=== CONT TestReadRedirectNar21442026/10/01 08:23:55 OK 20241026095416_initial_model.sql (8.37ms)21452026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.8ms)21462026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)21472026-10-01 08:23:55.298 UTC [1658] ERROR: relation "goose_db_version" does not exist at character 3621482026-10-01 08:23:55.298 UTC [1658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21492026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)21502026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.94ms)21512026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.47ms)21522026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)21532026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)21542026/10/01 08:23:55 OK 20260905000000_add_claims.sql (2.78ms)21552026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.45ms)21562026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.23ms)21572026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.17ms)21582026/10/01 08:23:55 OK 20241026095416_initial_model.sql (8.79ms)21592026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (1.92ms)21602026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000021612026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.76ms)21622026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000021632026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)21642026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2ms)21652026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.3ms)21662026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.54ms)21672026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.2ms)21682026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.63ms)21692026/10/01 08:23:55 OK 3_commit_push.sql (890.85µs)21702026/10/01 08:23:55 goose: up to current file version: 321712026/10/01 08:23:55 OK 3_commit_push.sql (1.16ms)21722026/10/01 08:23:55 goose: up to current file version: 32173--- PASS: TestService_ReadScope_PublicByDefault (0.54s)2174=== CONT TestReadProxyHead21752026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)21762026-10-01 08:23:55.322 UTC [1787] ERROR: relation "goose_db_version" does not exist at character 3621772026-10-01 08:23:55.322 UTC [1787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21782026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.46ms)21792026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (1.44ms)21802026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.51ms)21812026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000021822026/10/01 08:23:55 OK 1_commit_pending_closure.sql (4.25ms)21832026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.14ms)21842026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.64ms)21852026/10/01 08:23:55 OK 3_commit_push.sql (3.06ms)21862026/10/01 08:23:55 goose: up to current file version: 321872026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)21882026/10/01 08:23:55 OK 20251218171726_add_pins.sql (4.13ms)21892026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)21902026/10/01 08:23:55 OK 20260905000000_add_claims.sql (2.96ms)21912026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.59ms)21922026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.1ms)21932026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000021942026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.38ms)2195--- PASS: TestGetExistingObjectsLocksRows (0.49s)2196=== CONT TestReadProxyDisabled21972026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.07ms)21982026/10/01 08:23:55 OK 3_commit_push.sql (1.26ms)21992026/10/01 08:23:55 goose: up to current file version: 32200=== RUN TestService_RequireScope_OIDC/builder_may_write2201=== PAUSE TestService_RequireScope_OIDC/builder_may_write2202=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2203=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2204=== RUN TestService_RequireScope_OIDC/ops_may_admin2205=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2206=== RUN TestService_RequireScope_OIDC/ops_may_not_write2207=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2208=== RUN TestService_RequireScope_OIDC/reader_may_not_write2209=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2210=== RUN TestService_RequireScope_OIDC/static_token_may_admin2211=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2212=== RUN TestService_RequireScope_OIDC/static_token_may_write2213=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2214=== RUN TestService_RequireScope_OIDC/reader_may_read2215=== PAUSE TestService_RequireScope_OIDC/reader_may_read2216=== RUN TestService_RequireScope_OIDC/writer_implies_read2217=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2218=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2219=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2220=== CONT TestReadProxyInvalidPath2221=== NAME TestClientCADerivations2222 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2223 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2224 error: binary cache 's3://bucket36?endpoint=http://localhost:33673®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3862991666/001/store'2225 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12226--- PASS: TestClientCADerivations (1.11s)2227=== CONT TestService_AuthMiddleware_MTLSBoundSubjects22282026-10-01 08:23:55.391 UTC [1863] ERROR: relation "goose_db_version" does not exist at character 3622292026-10-01 08:23:55.391 UTC [1863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22302026/10/01 08:23:55 OK 20241026095416_initial_model.sql (8.46ms)22312026-10-01 08:23:55.409 UTC [1867] ERROR: relation "goose_db_version" does not exist at character 3622322026-10-01 08:23:55.409 UTC [1867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22332026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)22342026-10-01 08:23:55.409 UTC [1869] ERROR: relation "goose_db_version" does not exist at character 3622352026-10-01 08:23:55.409 UTC [1869] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22362026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.27ms)22372026/10/01 08:23:55 INFO Aborted multipart uploads count=022382026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)22392026/10/01 08:23:55 WARN Force mode enabled - objects will be deleted immediately without grace period2240--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.47s)2241=== CONT TestService_AuthMiddleware_MTLSProxyHeader22422026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.27ms)22432026/10/01 08:23: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=022442026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.03ms)22452026/10/01 08:23:55 INFO Vacuumed table table=pending_closures22462026/10/01 08:23:55 INFO Vacuumed table table=pending_objects22472026/10/01 08:23:55 INFO Vacuumed table table=multipart_uploads22482026/10/01 08:23:55 INFO Vacuumed table table=closures22492026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.49ms)22502026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.57ms)22512026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000022522026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.11ms)22532026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)22542026-10-01 08:23:55.427 UTC [1872] ERROR: relation "goose_db_version" does not exist at character 3622552026-10-01 08:23:55.427 UTC [1872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22562026/10/01 08:23:55 INFO Vacuumed table table=objects22572026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)22582026/10/01 08:23:55 OK 1_commit_pending_closure.sql (3.06ms)22592026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.43ms)22602026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.74ms)22612026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22622026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.27ms)22632026/10/01 08:23:55 INFO Aborted multipart uploads count=022642026/10/01 08:23:55 OK 3_commit_push.sql (1.3ms)22652026/10/01 08:23:55 goose: up to current file version: 322662026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)22672026/10/01 08:23:55 WARN Force mode enabled - objects will be deleted immediately without grace period22682026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes22692026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)22702026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.43ms)22712026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.42ms)22722026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.31ms)22732026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.02ms)22742026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000022752026/10/01 08:23:55 OK 20241026095416_initial_model.sql (9.67ms)22762026/10/01 08:23:55 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=022772026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.59ms)22782026/10/01 08:23:55 INFO Vacuumed table table=pending_closures22792026/10/01 08:23:55 INFO Vacuumed table table=pending_objects22802026/10/01 08:23:55 INFO Vacuumed table table=multipart_uploads22812026/10/01 08:23:55 INFO Vacuumed table table=closures22822026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)22832026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.57ms)22842026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000022852026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.96ms)22862026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22872026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.97ms)22882026/10/01 08:23:55 INFO Vacuumed table table=objects22892026/10/01 08:23:55 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjQzMWM4YWEtODQ4NC00ZDhlLThjMTMtYWRmMWJmZjJiM2JkLjlhZGMwMDRmLTZjZjktNDM2NS1hZWU4LTc5ZTJjNDY2NzQ4MXgxNzkwODQzMDM1MDU0NjY5ODQ5 parts=1022902026/10/01 08:23:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22912026/10/01 08:23:55 OK 2_object_stats_trigger.sql (4.62ms)2292--- PASS: TestSweepSkipsRowsLockedByPush (0.55s)22932026/10/01 08:23:55 OK 1_commit_pending_closure.sql (4.71ms)2294=== CONT TestService_ReadAuthMiddleware2295--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)2296=== CONT TestReadProxyNarinfoAlreadyDecompressed22972026/10/01 08:23:55 OK 2_object_stats_trigger.sql (15.81ms)22982026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (17.49ms)22992026/10/01 08:23:55 OK 3_commit_push.sql (16.03ms)23002026/10/01 08:23:55 goose: up to current file version: 323012026/10/01 08:23:55 INFO Completed upload id=123022026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete23032026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures23042026/10/01 08:23:55 OK 3_commit_push.sql (2.61ms)23052026/10/01 08:23:55 goose: up to current file version: 323062026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.68ms)23072026/10/01 08:23:55 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjQzMWM4YWEtODQ4NC00ZDhlLThjMTMtYWRmMWJmZjJiM2JkLjU5MzBlNTFhLTVjZWQtNDY0OC1iZTE0LTkwZTM3M2MwNzZlZngxNzkwODQzMDM1MDgzODM1Mzc2 parts=1023082026/10/01 08:23:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23092026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures23102026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes23112026/10/01 08:23:55 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo23122026/10/01 08:23:55 WARN Found objects in DB but missing from S3, will re-upload count=12313--- PASS: TestService_verifyS3Integrity (1.09s)2314=== CONT TestReadProxyNarStreaming23152026/10/01 08:23:55 INFO Completed upload id=123162026/10/01 08:23:55 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000023172026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (6.86ms)23182026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures23192026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.21ms)23202026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000023212026-10-01 08:23:55.481 UTC [1896] ERROR: relation "goose_db_version" does not exist at character 3623222026-10-01 08:23:55.481 UTC [1896] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23232026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.06ms)23242026/10/01 08:23:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures23252026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.52ms)23262026/10/01 08:23:55 OK 3_commit_push.sql (1.66ms)23272026/10/01 08:23:55 goose: up to current file version: 323282026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes23292026-10-01 08:23:55.496 UTC [1899] ERROR: relation "goose_db_version" does not exist at character 3623302026-10-01 08:23:55.496 UTC [1899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23312026/10/01 08:23:55 INFO Aborted multipart uploads count=023322026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.27ms)23332026-10-01 08:23:55.499 UTC [1901] ERROR: relation "goose_db_version" does not exist at character 3623342026-10-01 08:23:55.499 UTC [1901] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23352026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)23362026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.37ms)23372026/10/01 08:23:55 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=023382026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures23392026/10/01 08:23:55 INFO Vacuumed table table=pending_closures23402026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)23412026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/1/complete23422026/10/01 08:23:55 INFO Vacuumed table table=pending_objects23432026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.87ms)23442026/10/01 08:23:55 OK 20260905000000_add_claims.sql (4.04ms)23452026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)23462026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.88ms)23472026/10/01 08:23:55 INFO Vacuumed table table=multipart_uploads23482026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.28ms)23492026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)23502026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.17ms)23512026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.81ms)23522026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000023532026/10/01 08:23:55 INFO Vacuumed table table=closures2354--- PASS: TestPush_CompleteCommitsEveryRoot (0.46s)2355=== CONT TestReadProxyNarinfo23562026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.19ms)23572026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.29ms)23582026/10/01 08:23:55 INFO Vacuumed table table=objects23592026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)23602026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures23612026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.04ms)23622026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)23632026/10/01 08:23:55 OK 3_commit_push.sql (1.74ms)23642026/10/01 08:23:55 goose: up to current file version: 323652026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3ms)23662026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.07ms)23672026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.15ms)23682026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.54ms)23692026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000023702026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes23712026-10-01 08:23:55.532 UTC [1905] ERROR: relation "goose_db_version" does not exist at character 3623722026-10-01 08:23:55.532 UTC [1905] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23732026/10/01 08:23:55 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000023742026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.89ms)2375--- PASS: TestService_createPendingClosureHandler (1.14s)2376=== CONT TestIsValidCachePath2377=== RUN TestIsValidCachePath/narinfo2378=== PAUSE TestIsValidCachePath/narinfo2379=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2380=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2381=== RUN TestIsValidCachePath/nar_zst2382=== PAUSE TestIsValidCachePath/nar_zst2383=== RUN TestIsValidCachePath/nar_xz2384=== PAUSE TestIsValidCachePath/nar_xz2385=== RUN TestIsValidCachePath/nar_bz22386=== PAUSE TestIsValidCachePath/nar_bz22387=== RUN TestIsValidCachePath/nar_uncompressed23882026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.89ms)2389=== PAUSE TestIsValidCachePath/nar_uncompressed23902026/10/01 08:23:55 INFO Aborted multipart uploads count=02391=== RUN TestIsValidCachePath/ls2392=== PAUSE TestIsValidCachePath/ls2393=== RUN TestIsValidCachePath/log2394=== PAUSE TestIsValidCachePath/log2395=== RUN TestIsValidCachePath/realisation2396=== PAUSE TestIsValidCachePath/realisation2397=== RUN TestIsValidCachePath/nix-cache-info2398=== PAUSE TestIsValidCachePath/nix-cache-info2399=== RUN TestIsValidCachePath/index.html2400=== PAUSE TestIsValidCachePath/index.html2401=== RUN TestIsValidCachePath/traversal_parent2402=== PAUSE TestIsValidCachePath/traversal_parent2403=== RUN TestIsValidCachePath/traversal_in_middle24042026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.38ms)2405=== PAUSE TestIsValidCachePath/traversal_in_middle24062026/10/01 08:23:55 goose: successfully migrated database to version: 202609231200002407=== RUN TestIsValidCachePath/invalid_char_e2408=== PAUSE TestIsValidCachePath/invalid_char_e2409=== RUN TestIsValidCachePath/invalid_char_u2410=== PAUSE TestIsValidCachePath/invalid_char_u2411=== RUN TestIsValidCachePath/random_path2412=== PAUSE TestIsValidCachePath/random_path2413=== RUN TestIsValidCachePath/empty2414=== PAUSE TestIsValidCachePath/empty2415=== RUN TestIsValidCachePath/leading_slash2416=== PAUSE TestIsValidCachePath/leading_slash2417=== RUN TestIsValidCachePath/wrong_extension2418=== PAUSE TestIsValidCachePath/wrong_extension2419=== RUN TestIsValidCachePath/short_hash2420=== PAUSE TestIsValidCachePath/short_hash2421=== CONT TestFailedS3DeleteKeepsTombstone24222026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.74ms)24232026/10/01 08:23:55 WARN Force mode enabled - objects will be deleted immediately without grace period24242026/10/01 08:23:55 OK 3_commit_push.sql (2.41ms)24252026/10/01 08:23:55 goose: up to current file version: 324262026/10/01 08:23:55 OK 1_commit_pending_closure.sql (3.18ms)24272026/10/01 08:23:55 OK 2_object_stats_trigger.sql (9.76ms)24282026/10/01 08:23:55 OK 20241026095416_initial_model.sql (13.66ms)24292026/10/01 08:23:55 OK 3_commit_push.sql (5.1ms)24302026/10/01 08:23:55 goose: up to current file version: 324312026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)24322026/10/01 08:23:55 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=024332026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.61ms)2434--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.39s)2435=== CONT TestServerTLSConfig/no_client_CA2436=== CONT TestServerTLSConfig/not_a_PEM_file2437=== CONT TestServerTLSConfig/missing_CA_file24382026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)2439--- PASS: TestServerTLSConfig (0.01s)2440 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2441 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2442 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2443=== CONT TestParseSingleRange/none2444=== CONT TestParseSingleRange/open-ended2445=== CONT TestParseSingleRange/start_far_past_EOF2446=== CONT TestParseSingleRange/start_past_EOF2447=== CONT TestParseSingleRange/single_byte2448=== CONT TestParseSingleRange/suffix_exceeds_size2449=== CONT TestParseSingleRange/suffix2450=== CONT TestParseSingleRange/end_clamped_to_size2451=== CONT TestParseSingleRange/malformed_both_empty2452=== CONT TestParseSingleRange/closed2453=== CONT TestParseSingleRange/malformed_end_before_start2454=== CONT TestParseSingleRange/multi-range_ignored2455=== CONT TestParseSingleRange/malformed_no_dash2456=== CONT TestParseSingleRange/unknown_unit24572026/10/01 08:23:55 INFO Vacuumed table table=pending_closures2458--- PASS: TestParseSingleRange (0.01s)2459 --- PASS: TestParseSingleRange/none (0.00s)2460 --- PASS: TestParseSingleRange/open-ended (0.00s)2461 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2462 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2463 --- PASS: TestParseSingleRange/single_byte (0.00s)2464 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2465 --- PASS: TestParseSingleRange/suffix (0.00s)2466 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2467 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2468 --- PASS: TestParseSingleRange/closed (0.00s)2469 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2470 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2471 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2472 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2473=== CONT TestResolveDBConnectionString/flag_wins2474=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2475=== CONT TestResolveDBConnectionString/nothing_configured2476=== CONT TestResolveDBConnectionString/missing_file_is_an_error2477=== CONT TestResolveDBConnectionString/file_when_flag_empty2478=== CONT TestClientErrorHandling/InvalidStorePath2479--- PASS: TestResolveDBConnectionString (0.00s)2480 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2481 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2482 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2483 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2484 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)24852026/10/01 08:23:55 OK 20260905000000_add_claims.sql (4.7ms)24862026/10/01 08:23:55 INFO Vacuumed table table=pending_objects24872026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.19ms)24882026/10/01 08:23:55 INFO Vacuumed table table=multipart_uploads2489--- PASS: TestReadRedirectUsesPublicS3URL (0.40s)2490=== CONT TestClientErrorHandling/ServerNotAvailable24912026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.41ms)24922026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000024932026-10-01 08:23:55.575 UTC [1912] ERROR: relation "goose_db_version" does not exist at character 3624942026-10-01 08:23:55.575 UTC [1912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24952026/10/01 08:23:55 INFO Vacuumed table table=closures24962026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.17ms)24972026/10/01 08:23:55 OK 2_object_stats_trigger.sql (1.36ms)24982026-10-01 08:23:55.579 UTC [1914] ERROR: relation "goose_db_version" does not exist at character 3624992026-10-01 08:23:55.579 UTC [1914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25002026/10/01 08:23:55 INFO Vacuumed table table=objects25012026/10/01 08:23:55 OK 3_commit_push.sql (1.15ms)25022026/10/01 08:23:55 goose: up to current file version: 325032026/10/01 08:23:55 INFO Received complete push request method=POST path=/api/pushes/2/complete2504--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.57s)2505=== CONT TestClientErrorHandling/InvalidAuthToken2506--- PASS: TestReadProxyRangeRequest (0.40s)2507=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info25082026/10/01 08:23:55 INFO Received uploads request method=POST path=/2509=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key25102026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/2511=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25122026/10/01 08:23:55 INFO Received request for more parts method=POST path=/2513=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25142026/10/01 08:23:55 INFO Received uploads request method=POST path=/2515=== CONT TestIsValidUploadKey/narinfo2516=== CONT TestIsValidUploadKey/realisation_plus_in_output2517=== CONT TestIsValidUploadKey/realisation2518=== CONT TestIsValidUploadKey/build_log_equals2519=== CONT TestIsValidUploadKey/build_log_question_mark2520=== CONT TestIsValidUploadKey/build_log_plus_in_name2521=== CONT TestIsValidUploadKey/build_log_home-manager_file2522=== CONT TestIsValidUploadKey/build_log2523=== CONT TestIsValidUploadKey/listing2524=== CONT TestIsValidUploadKey/nar_plain2525=== CONT TestIsValidUploadKey/nar_xz2526=== CONT TestIsValidUploadKey/nar_zst2527--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2528 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2529 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2530 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2531 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2532=== CONT TestIsValidUploadKey/traversal_nar25332026-10-01 08:23:55.590 UTC [1916] ERROR: relation "goose_db_version" does not exist at character 3625342026-10-01 08:23:55.590 UTC [1916] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2535=== CONT TestIsValidUploadKey/nix-cache-info2536=== CONT TestIsValidUploadKey/traversal2537=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2538=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2539=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2540=== CONT TestIsValidUploadKey/index.html2541=== CONT TestIsValidUploadKey/empty_key2542=== CONT TestIsValidUploadKey/unknown_type2543=== CONT TestIsValidUploadKey/absolute2544--- PASS: TestIsValidUploadKey (0.00s)2545 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2546 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2547 --- PASS: TestIsValidUploadKey/realisation (0.00s)2548 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2549 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2550 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2551 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2552 --- PASS: TestIsValidUploadKey/build_log (0.00s)2553 --- PASS: TestIsValidUploadKey/listing (0.00s)2554 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2555 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2556 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2557 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2558 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2559 --- PASS: TestIsValidUploadKey/traversal (0.00s)2560 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2561 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2562 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2563 --- PASS: TestIsValidUploadKey/index.html (0.00s)2564 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2565 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2566 --- PASS: TestIsValidUploadKey/absolute (0.00s)2567=== CONT TestProxyWriteTimeout/narinfo2568=== CONT TestProxyWriteTimeout/10_GiB_nar2569=== CONT TestProxyWriteTimeout/unknown_size2570=== CONT TestProxyWriteTimeout/1_GiB_nar2571--- PASS: TestProxyWriteTimeout (0.00s)2572 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2573 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2574 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2575 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2576=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25772026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/25782026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.94ms)25792026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)25802026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.5ms)25812026/10/01 08:23:55 OK 20241026095416_initial_model.sql (11.75ms)25822026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)25832026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)25842026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.49ms)25852026/10/01 08:23:55 OK 20260905000000_add_claims.sql (4.71ms)2586--- PASS: TestReadProxy404 (0.39s)2587=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25882026/10/01 08:23:55 INFO Received request for more parts method=POST path=/25892026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)25902026/10/01 08:23:55 OK 20241026095416_initial_model.sql (10.96ms)25912026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)25922026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (2.84ms)25932026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.56ms)25942026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.82ms)25952026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000025962026/10/01 08:23:55 OK 20251218171726_add_pins.sql (4.14ms)25972026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.18ms)25982026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.67ms)25992026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.08ms)26002026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000026012026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.34ms)26022026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)26032026/10/01 08:23:55 OK 1_commit_pending_closure.sql (3.72ms)26042026/10/01 08:23:55 OK 3_commit_push.sql (2.88ms)26052026/10/01 08:23:55 goose: up to current file version: 326062026/10/01 08:23:55 OK 20260905000000_add_claims.sql (4.5ms)26072026/10/01 08:23:55 OK 2_object_stats_trigger.sql (2.85ms)26082026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.06ms)26092026/10/01 08:23:55 OK 3_commit_push.sql (2ms)26102026/10/01 08:23:55 goose: up to current file version: 326112026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (3.52ms)26122026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000026132026-10-01 08:23:55.646 UTC [1953] ERROR: relation "goose_db_version" does not exist at character 3626142026-10-01 08:23:55.646 UTC [1953] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26152026/10/01 08:23:55 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/present26162026/10/01 08:23:55 OK 1_commit_pending_closure.sql (21.49ms)2617=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure26182026/10/01 08:23:55 INFO Received uploads request method=POST path=/2619--- PASS: TestReadRedirectKeepsNarinfoProxied (0.39s)2620=== CONT TestCacheConfigHandler/full_config,_no_issuer2621=== CONT TestCacheConfigHandler/no_signing_keys2622=== CONT TestCacheConfigHandler/no_cache_url_configured2623=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2624--- PASS: TestCacheConfigHandler (0.00s)2625 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2626 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2627 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2628 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2629=== CONT TestPush_RejectsBadRequests/no_roots26302026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes2631=== CONT TestPush_RejectsBadRequests/bad_root26322026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes2633=== CONT TestPush_RejectsBadRequests/root_not_in_objects26342026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes2635=== CONT TestPush_RejectsBadRequests/no_objects26362026/10/01 08:23:55 INFO Received push request method=POST path=/api/pushes2637=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2638--- PASS: TestPush_RejectsBadRequests (0.64s)2639 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2640 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2641 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2642 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)26432026/10/01 08:23:55 OK 2_object_stats_trigger.sql (7.19ms)2644=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected26452026/10/01 08:23:55 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]2646=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2647=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26482026/10/01 08:23:55 OK 3_commit_push.sql (2.56ms)26492026/10/01 08:23:55 goose: up to current file version: 326502026/10/01 08:23:55 WARN Authentication failed token_preview=eyJhbGciOi...l23762JtZg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2651=== CONT TestService_RequireScope_OIDC/builder_may_write2652--- PASS: TestService_AuthMiddleware_OIDC (0.56s)2653 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2654 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2655 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2656 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2657=== CONT TestService_RequireScope_OIDC/static_token_may_admin2658=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2659=== CONT TestService_RequireScope_OIDC/writer_implies_read2660=== CONT TestService_RequireScope_OIDC/reader_may_read26612026/10/01 08:23:55 OK 20241026095416_initial_model.sql (11.11ms)2662=== CONT TestService_RequireScope_OIDC/static_token_may_write2663=== CONT TestService_RequireScope_OIDC/reader_may_not_write2664=== CONT TestService_RequireScope_OIDC/ops_may_admin2665=== CONT TestService_RequireScope_OIDC/ops_may_not_write2666=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2667=== CONT TestIsValidCachePath/narinfo2668=== CONT TestIsValidCachePath/index.html2669=== CONT TestIsValidCachePath/short_hash2670=== CONT TestIsValidCachePath/wrong_extension26712026-10-01 08:23:55.670 UTC [1954] ERROR: relation "goose_db_version" does not exist at character 3626722026-10-01 08:23:55.670 UTC [1954] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2673=== CONT TestIsValidCachePath/leading_slash2674=== CONT TestIsValidCachePath/empty2675=== CONT TestIsValidCachePath/random_path2676=== CONT TestIsValidCachePath/invalid_char_u2677=== CONT TestIsValidCachePath/invalid_char_e2678=== CONT TestIsValidCachePath/traversal_in_middle2679=== CONT TestIsValidCachePath/traversal_parent2680=== CONT TestIsValidCachePath/nar_uncompressed2681=== CONT TestIsValidCachePath/nix-cache-info2682=== CONT TestIsValidCachePath/realisation2683=== CONT TestIsValidCachePath/log2684=== CONT TestIsValidCachePath/ls2685=== CONT TestIsValidCachePath/nar_xz2686=== CONT TestIsValidCachePath/nar_bz22687--- PASS: TestService_RequireScope_OIDC (0.54s)2688 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2689 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2690 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2691 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2692 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2693 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2694 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2695 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2696 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2697 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2698=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2699=== CONT TestIsValidCachePath/nar_zst2700--- PASS: TestIsValidCachePath (0.00s)2701 --- PASS: TestIsValidCachePath/narinfo (0.00s)2702 --- PASS: TestIsValidCachePath/index.html (0.00s)2703 --- PASS: TestIsValidCachePath/short_hash (0.00s)2704 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2705 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2706 --- PASS: TestIsValidCachePath/empty (0.00s)2707 --- PASS: TestIsValidCachePath/random_path (0.00s)2708 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2709 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2710 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2711 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2712 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2713 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2714 --- PASS: TestIsValidCachePath/realisation (0.00s)2715 --- PASS: TestIsValidCachePath/log (0.00s)2716 --- PASS: TestIsValidCachePath/ls (0.00s)2717 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2718 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2719 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2720 --- PASS: TestIsValidCachePath/nar_zst (0.00s)27212026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (4.05ms)27222026/10/01 08:23:55 OK 20251218171726_add_pins.sql (3.13ms)27232026/10/01 08:23:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete27242026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)27252026/10/01 08:23:55 OK 20260905000000_add_claims.sql (3.8ms)27262026/10/01 08:23:55 OK 20241026095416_initial_model.sql (8.6ms)2727--- PASS: TestReadRedirectNar (0.39s)27282026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)27292026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (1.99ms)27302026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.43ms)27312026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (2.2ms)27322026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000027332026/10/01 08:23:55 OK 1_commit_pending_closure.sql (2.33ms)27342026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)27352026/10/01 08:23:55 OK 2_object_stats_trigger.sql (934.76µs)27362026/10/01 08:23:55 OK 3_commit_push.sql (679.32µs)27372026/10/01 08:23:55 goose: up to current file version: 327382026/10/01 08:23:55 OK 20260905000000_add_claims.sql (2.14ms)27392026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (1.45ms)27402026/10/01 08:23:55 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjQzMWM4YWEtODQ4NC00ZDhlLThjMTMtYWRmMWJmZjJiM2JkLmVjNjljNjQ0LWUwNGQtNGVjMC1hMGFkLTc1MjM1MWZjYTNiMXgxNzkwODQzMDM1MjU5NjUxMjI0 parts=1227412026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (1.04ms)27422026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000027432026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures27442026-10-01 08:23:55.697 UTC [1955] ERROR: relation "goose_db_version" does not exist at character 3627452026-10-01 08:23:55.697 UTC [1955] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27462026/10/01 08:23:55 OK 1_commit_pending_closure.sql (1.58ms)2747--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.08s)27482026/10/01 08:23:55 OK 2_object_stats_trigger.sql (729.6µs)27492026/10/01 08:23:55 OK 3_commit_push.sql (623.01µs)27502026/10/01 08:23:55 goose: up to current file version: 327512026-10-01 08:23:55.705 UTC [1956] ERROR: relation "goose_db_version" does not exist at character 3627522026-10-01 08:23:55.705 UTC [1956] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2753--- PASS: TestReadProxyConditionalGet (0.42s)27542026/10/01 08:23:55 OK 20241026095416_initial_model.sql (7.11ms)27552026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (999.58µs)27562026/10/01 08:23:55 OK 20251218171726_add_pins.sql (2.59ms)27572026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (3.09ms)27582026/10/01 08:23:55 OK 20241026095416_initial_model.sql (7.48ms)27592026/10/01 08:23:55 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)27602026/10/01 08:23:55 OK 20260905000000_add_claims.sql (2.19ms)27612026/10/01 08:23:55 OK 20251218171726_add_pins.sql (1.91ms)27622026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (1.53ms)27632026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (1.39ms)27642026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000027652026/10/01 08:23:55 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)27662026/10/01 08:23:55 OK 1_commit_pending_closure.sql (1.39ms)27672026/10/01 08:23:55 OK 2_object_stats_trigger.sql (662.2µs)27682026/10/01 08:23:55 OK 20260905000000_add_claims.sql (2.05ms)27692026/10/01 08:23:55 OK 3_commit_push.sql (577.06µs)27702026/10/01 08:23:55 goose: up to current file version: 327712026/10/01 08:23:55 OK 20260920000000_drop_claims.sql (3.02ms)27722026/10/01 08:23:55 OK 20260923120000_add_pushes.sql (1.07ms)27732026/10/01 08:23:55 goose: successfully migrated database to version: 2026092312000027742026/10/01 08:23:55 OK 1_commit_pending_closure.sql (1.45ms)27752026/10/01 08:23:55 OK 2_object_stats_trigger.sql (640.41µs)27762026/10/01 08:23:55 OK 3_commit_push.sql (468.58µs)27772026/10/01 08:23:55 goose: up to current file version: 32778--- PASS: TestReadProxyHead (0.41s)27792026/10/01 08:23:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.489223ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2780--- PASS: TestReadProxyDisabled (0.39s)2781--- PASS: TestReadProxyInvalidPath (0.40s)27822026/10/01 08:23:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"27832026/10/01 08:23:55 WARN mTLS auth: bound subjects configured but subject DN unavailable27842026/10/01 08:23:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2785--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.41s)2786--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.40s)2787--- PASS: TestService_ReadAuthMiddleware (0.40s)2788=== NAME TestOrphanedObjectsGCStressTest2789 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2790--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.42s)2791=== NAME TestOrphanedObjectsGCStressTest2792 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2793--- PASS: TestReadProxyNarStreaming (0.43s)2794--- PASS: TestReadProxyNarinfo (0.41s)27952026/10/01 08:23:55 INFO Received uploads request method=POST path=/api/pending_closures27962026/10/01 08:23:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.267225ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27972026/10/01 08:23:56 INFO Aborted multipart uploads count=027982026/10/01 08:23:56 WARN Force mode enabled - objects will be deleted immediately without grace period27992026/10/01 08:23:56 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."28002026/10/01 08:23:56 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."28012026/10/01 08:23:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2802--- PASS: TestFailedS3DeleteKeepsTombstone (0.50s)28032026/10/01 08:23:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjQzMWM4YWEtODQ4NC00ZDhlLThjMTMtYWRmMWJmZjJiM2JkLmI0MzU2ZmU1LTRlZjktNDhjOS1hM2Q2LTBiODI1NWZkMWZmOHgxNzkwODQzMDM1NTE4NzgzMzk0 parts=122804--- PASS: TestRedundantMultipartUpload (0.93s)28052026/10/01 08:23:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28062026/10/01 08:23:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2807=== NAME TestOrphanedObjectsGCStressTest2808 orphaned_objects_gc_test.go:509: Stress test completed successfully:2809 orphaned_objects_gc_test.go:510: - Active objects preserved: 202810 orphaned_objects_gc_test.go:511: - Objects deleted: 2102811 orphaned_objects_gc_test.go:512: - Total GC'd: 2102812--- PASS: TestOrphanedObjectsGCStressTest (2.66s)2813--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2814 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2815 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2816 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)28172026/10/01 08:23:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=735.196752ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28182026/10/01 08:23:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02819=== NAME TestPinProtectsFromGC2820 client_integration_test.go:794: Pin successfully protected closure from garbage collection2821--- PASS: TestPinProtectsFromGC (3.16s)28222026/10/01 08:23:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.573735115s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28232026/10/01 08:23:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02824=== NAME TestClientIntegration2825 client_integration_test.go:323: Objects in database after GC:2826 client_integration_test.go:323: Successfully deleted all objects with GC --force2827--- PASS: TestClientIntegration (2.91s)28282026/10/01 08:23:58 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-config28292026/10/01 08:23:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.495933ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28302026/10/01 08:23:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.137389ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28312026/10/01 08:23:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=869.228092ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28322026/10/01 08:23:59 WARN Rate limiter enabled after throttle name=s3-test rate=528332026/10/01 08:23:59 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2834=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2835 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102836 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002837--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.88s)28382026/10/01 08:24:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.622650748s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28392026/10/01 08:24:01 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"28402026/10/01 08:24:01 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-config28412026/10/01 08:24:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.447843ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28422026/10/01 08:24:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.028991ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28432026/10/01 08:24:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=832.139ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28442026/10/01 08:24:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.468146344s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28452026/10/01 08:24:04 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_closures28462026/10/01 08:24:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.435462ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28472026/10/01 08:24:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.919949ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28482026/10/01 08:24:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=836.425961ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28492026/10/01 08:24:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.737311334s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2850--- PASS: TestClientErrorHandling (0.00s)2851 --- PASS: TestClientErrorHandling/InvalidStorePath (0.45s)2852 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.52s)2853 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.57s)2854PASS2855{"timestamp":"2026-10-01T08:24:08.143954602Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:34764","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(397)"}28562026-10-01 08:24:08.466 UTC [128] LOG: received smart shutdown request28572026-10-01 08:24:08.470 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 128582026-10-01 08:24:08.480 UTC [133] LOG: shutting down28592026-10-01 08:24:08.481 UTC [133] LOG: checkpoint starting: shutdown immediate28602026-10-01 08:24:09.654 UTC [133] LOG: checkpoint complete: wrote 10662 buffers (65.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 21 recycled; write=0.263 s, sync=0.876 s, total=1.174 s; sync files=25265, longest=0.005 s, average=0.001 s; distance=343754 kB, estimate=343754 kB; lsn=0/16718728, redo lsn=0/1671872828612026-10-01 08:24:09.734 UTC [128] LOG: database system is shut down2862Running OIDC tests...2863=== RUN TestAudienceForIssuer2864=== PAUSE TestAudienceForIssuer2865=== RUN TestGlobMatch2866=== PAUSE TestGlobMatch2867=== RUN TestValidateToken_ValidToken2868=== PAUSE TestValidateToken_ValidToken2869=== RUN TestValidateToken_WrongAudience2870=== PAUSE TestValidateToken_WrongAudience2871=== RUN TestValidateToken_Expired2872=== PAUSE TestValidateToken_Expired2873=== RUN TestValidateToken_BoundClaimsMismatch2874=== PAUSE TestValidateToken_BoundClaimsMismatch2875=== RUN TestValidateToken_BoundSubjectMismatch2876=== PAUSE TestValidateToken_BoundSubjectMismatch2877=== RUN TestValidateToken_MultipleProviders2878=== PAUSE TestValidateToken_MultipleProviders2879=== RUN TestValidateToken_NoMatchingProvider2880=== PAUSE TestValidateToken_NoMatchingProvider2881=== RUN TestValidateToken_KubernetesServiceAccount2882=== PAUSE TestValidateToken_KubernetesServiceAccount2883=== RUN TestNewValidator_KubernetesRequiresCA2884=== PAUSE TestNewValidator_KubernetesRequiresCA2885=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2886=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2887=== RUN TestPins_ReservedForMatchingRule2888=== PAUSE TestPins_ReservedForMatchingRule2889=== RUN TestPins_TopLevelShorthand2890=== PAUSE TestPins_TopLevelShorthand2891=== RUN TestPins_ConfigValidation2892=== PAUSE TestPins_ConfigValidation2893=== RUN TestScopes_LegacyProviderDefaultsToWrite2894=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2895=== RUN TestScopes_Rules2896=== PAUSE TestScopes_Rules2897=== RUN TestScopes_ConfigValidation2898=== PAUSE TestScopes_ConfigValidation2899=== CONT TestAudienceForIssuer2900=== CONT TestPins_ConfigValidation2901=== CONT TestValidateToken_KubernetesServiceAccount2902=== CONT TestPins_TopLevelShorthand2903--- PASS: TestAudienceForIssuer (0.00s)2904=== CONT TestPins_ReservedForMatchingRule2905=== CONT TestValidateToken_Expired2906=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2907=== CONT TestValidateToken_WrongAudience2908--- PASS: TestPins_ConfigValidation (0.00s)2909=== CONT TestValidateToken_ValidToken2910=== CONT TestNewValidator_KubernetesRequiresCA2911=== CONT TestGlobMatch2912=== RUN TestGlobMatch/foo_foo2913=== PAUSE TestGlobMatch/foo_foo2914=== RUN TestGlobMatch/foo_bar2915=== PAUSE TestGlobMatch/foo_bar2916=== RUN TestGlobMatch/*_2917=== PAUSE TestGlobMatch/*_2918=== RUN TestGlobMatch/*_anything2919=== PAUSE TestGlobMatch/*_anything2920=== RUN TestGlobMatch/foo*_foo2921=== PAUSE TestGlobMatch/foo*_foo2922=== RUN TestGlobMatch/foo*_foobar2923=== PAUSE TestGlobMatch/foo*_foobar2924=== CONT TestValidateToken_MultipleProviders2925=== CONT TestScopes_Rules2926=== CONT TestValidateToken_NoMatchingProvider2927=== CONT TestScopes_ConfigValidation2928=== CONT TestScopes_LegacyProviderDefaultsToWrite2929=== CONT TestValidateToken_BoundSubjectMismatch2930=== CONT TestValidateToken_BoundClaimsMismatch2931=== RUN TestGlobMatch/foo*_bar2932=== PAUSE TestGlobMatch/foo*_bar2933=== RUN TestGlobMatch/*bar_bar2934=== PAUSE TestGlobMatch/*bar_bar2935=== RUN TestGlobMatch/*bar_foobar2936=== PAUSE TestGlobMatch/*bar_foobar2937=== RUN TestGlobMatch/*bar_foo2938=== PAUSE TestGlobMatch/*bar_foo2939=== RUN TestGlobMatch/foo*bar_foobar2940=== PAUSE TestGlobMatch/foo*bar_foobar2941=== RUN TestGlobMatch/foo*bar_foo123bar2942=== PAUSE TestGlobMatch/foo*bar_foo123bar2943=== RUN TestGlobMatch/foo*bar_foobarbaz2944=== PAUSE TestGlobMatch/foo*bar_foobarbaz2945=== RUN TestGlobMatch/*/*_foo/bar2946=== PAUSE TestGlobMatch/*/*_foo/bar2947=== RUN TestGlobMatch/*/*_foo2948=== PAUSE TestGlobMatch/*/*_foo2949=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2950=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2951=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02952=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02953=== RUN TestGlobMatch/refs/*/main_refs/heads/main2954=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2955=== RUN TestGlobMatch/fo?_foo2956=== PAUSE TestGlobMatch/fo?_foo2957=== RUN TestGlobMatch/fo?_fo2958=== PAUSE TestGlobMatch/fo?_fo2959=== RUN TestGlobMatch/fo?_fooo2960=== PAUSE TestGlobMatch/fo?_fooo2961=== RUN TestGlobMatch/?oo_foo2962=== PAUSE TestGlobMatch/?oo_foo2963=== RUN TestGlobMatch/?oo_boo2964=== PAUSE TestGlobMatch/?oo_boo2965=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2966=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2967=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2968=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2969=== CONT TestGlobMatch/foo_foo2970=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2971=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2972=== CONT TestGlobMatch/?oo_boo2973--- PASS: TestScopes_ConfigValidation (0.00s)2974=== CONT TestGlobMatch/?oo_foo2975=== CONT TestGlobMatch/foo*bar_foo123bar2976=== CONT TestGlobMatch/foo*bar_foobar2977=== CONT TestGlobMatch/*bar_foo2978=== CONT TestGlobMatch/*bar_foobar2979=== CONT TestGlobMatch/*bar_bar2980=== CONT TestGlobMatch/foo*_bar2981=== CONT TestGlobMatch/foo*_foobar2982=== CONT TestGlobMatch/foo*_foo2983=== CONT TestGlobMatch/*_anything2984=== CONT TestGlobMatch/*_2985=== CONT TestGlobMatch/foo_bar2986=== CONT TestGlobMatch/fo?_fooo2987=== CONT TestGlobMatch/fo?_fo2988=== CONT TestGlobMatch/fo?_foo2989=== CONT TestGlobMatch/refs/*/main_refs/heads/main2990=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02991=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2992=== CONT TestGlobMatch/*/*_foo2993=== CONT TestGlobMatch/*/*_foo/bar2994=== CONT TestGlobMatch/foo*bar_foobarbaz2995--- PASS: TestGlobMatch (0.00s)2996 --- PASS: TestGlobMatch/foo_foo (0.00s)2997 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2998 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2999 --- PASS: TestGlobMatch/?oo_boo (0.00s)3000 --- PASS: TestGlobMatch/?oo_foo (0.00s)3001 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3002 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3003 --- PASS: TestGlobMatch/*bar_foo (0.00s)3004 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3005 --- PASS: TestGlobMatch/*bar_bar (0.00s)3006 --- PASS: TestGlobMatch/foo*_bar (0.00s)3007 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3008 --- PASS: TestGlobMatch/foo*_foo (0.00s)3009 --- PASS: TestGlobMatch/*_anything (0.00s)3010 --- PASS: TestGlobMatch/*_ (0.00s)3011 --- PASS: TestGlobMatch/foo_bar (0.00s)3012 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3013 --- PASS: TestGlobMatch/fo?_fo (0.00s)3014 --- PASS: TestGlobMatch/fo?_foo (0.00s)3015 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3016 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3017 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3018 --- PASS: TestGlobMatch/*/*_foo (0.00s)3019 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3020 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)30212026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40263/oidc3022--- PASS: TestPins_ReservedForMatchingRule (0.02s)30232026/10/01 08:24:11 http: TLS handshake error from 127.0.0.1:51516: remote error: tls: bad certificate3024--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)30252026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34129/oidc3026--- PASS: TestValidateToken_WrongAudience (0.03s)30272026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43707/oidc30282026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32915/oidc30292026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35001/oidc3030--- PASS: TestValidateToken_ValidToken (0.06s)3031--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)3032--- PASS: TestPins_TopLevelShorthand (0.06s)30332026/10/01 08:24:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41443/oidc30342026/10/01 08:24:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46243/oidc3035--- PASS: TestValidateToken_MultipleProviders (0.07s)30362026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36819/oidc30372026/10/01 08:24:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36657/oidc3038--- PASS: TestValidateToken_Expired (0.08s)3039--- PASS: TestValidateToken_NoMatchingProvider (0.08s)30402026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40357/oidc3041--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)30422026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36507/oidc30432026/10/01 08:24:11 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233044--- PASS: TestScopes_Rules (0.11s)30452026/10/01 08:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35389/oidc3046--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)3047--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)30482026/10/01 08:24:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:371933049--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)3050PASS3051Running hook tests...3052=== RUN TestSendPathsEmpty3053=== PAUSE TestSendPathsEmpty3054=== RUN TestQueueEnqueueAndFetch3055=== PAUSE TestQueueEnqueueAndFetch3056=== RUN TestQueueDeduplication3057=== PAUSE TestQueueDeduplication3058=== RUN TestQueueRemove3059=== PAUSE TestQueueRemove3060=== RUN TestQueueFetchBatchLimit3061=== PAUSE TestQueueFetchBatchLimit3062=== RUN TestQueueRetryMovesToBack3063=== PAUSE TestQueueRetryMovesToBack3064=== RUN TestQueueFetchRemoveLifecycle3065=== PAUSE TestQueueFetchRemoveLifecycle3066=== RUN TestQueueConcurrentWriters3067=== PAUSE TestQueueConcurrentWriters3068=== RUN TestQueueRemoveLargeClosure3069=== PAUSE TestQueueRemoveLargeClosure3070=== RUN TestServerClientIntegration3071=== PAUSE TestServerClientIntegration3072=== RUN TestServerQueueError3073=== PAUSE TestServerQueueError3074=== RUN TestGetListenerSocketActivation3075 server_test.go:210: === RUN TestGetListenerSocketActivation3076 --- PASS: TestGetListenerSocketActivation (0.00s)3077 PASS3078 3079--- PASS: TestGetListenerSocketActivation (0.01s)3080=== RUN TestDrainIsolatesPoisonPath3081=== PAUSE TestDrainIsolatesPoisonPath3082=== RUN TestRunNotBlockedByPoisonHead3083=== PAUSE TestRunNotBlockedByPoisonHead3084=== RUN TestDrainGivesUpWhenServerDown3085=== PAUSE TestDrainGivesUpWhenServerDown3086=== RUN TestFailedPathPrunedByLaterClosure3087=== PAUSE TestFailedPathPrunedByLaterClosure3088=== RUN TestWorkerUploadsAndRemoves3089=== PAUSE TestWorkerUploadsAndRemoves3090=== RUN TestWorkerSkipsGCdPaths3091=== PAUSE TestWorkerSkipsGCdPaths3092=== RUN TestWorkerPrunesClosureDeps3093=== PAUSE TestWorkerPrunesClosureDeps3094=== RUN TestDrainTimeout3095=== PAUSE TestDrainTimeout3096=== CONT TestSendPathsEmpty3097=== CONT TestServerQueueError3098=== CONT TestDrainGivesUpWhenServerDown3099--- PASS: TestSendPathsEmpty (0.00s)3100=== CONT TestServerClientIntegration3101=== CONT TestQueueRemoveLargeClosure3102=== CONT TestQueueConcurrentWriters3103=== CONT TestQueueFetchRemoveLifecycle31042026/10/01 08:24:11 ERROR Failed to queue paths error="permission denied" count=13105=== CONT TestQueueRetryMovesToBack3106=== CONT TestQueueFetchBatchLimit3107=== CONT TestQueueRemove3108=== CONT TestQueueDeduplication3109=== CONT TestQueueEnqueueAndFetch3110=== CONT TestWorkerUploadsAndRemoves3111=== CONT TestDrainTimeout3112=== CONT TestWorkerPrunesClosureDeps3113=== CONT TestWorkerSkipsGCdPaths3114=== CONT TestRunNotBlockedByPoisonHead3115=== CONT TestDrainIsolatesPoisonPath3116=== CONT TestFailedPathPrunedByLaterClosure3117--- PASS: TestServerQueueError (0.00s)3118--- PASS: TestServerClientIntegration (0.00s)31192026/10/01 08:24:11 INFO Upload queue status pending=231202026/10/01 08:24:11 INFO Uploading batch count=231212026/10/01 08:24:11 INFO Uploading batch count=431222026/10/01 08:24:11 INFO Uploading batch count=231232026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=431242026/10/01 08:24:11 INFO Uploading batch count=131252026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=131262026/10/01 08:24:11 INFO Uploading batch count=231272026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=231282026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526834684/002/a31292026/10/01 08:24:11 INFO Upload queue status pending=23130--- PASS: TestQueueFetchBatchLimit (0.02s)31312026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath994092524/002/bbb3132--- PASS: TestQueueDeduplication (0.02s)31332026/10/01 08:24:11 INFO Upload queue status pending=33134--- PASS: TestQueueEnqueueAndFetch (0.02s)31352026/10/01 08:24:11 INFO Uploading batch count=131362026/10/01 08:24:11 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3926155876/002/nonexistent31372026/10/01 08:24:11 INFO Upload queue status pending=231382026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526834684/002/b31392026/10/01 08:24:11 INFO Uploading batch count=131402026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=13141--- PASS: TestQueueRetryMovesToBack (0.02s)3142--- PASS: TestQueueRemove (0.02s)31432026/10/01 08:24:11 INFO Uploading batch count=131442026/10/01 08:24:11 INFO Uploading batch count=13145--- PASS: TestQueueFetchRemoveLifecycle (0.02s)31462026/10/01 08:24:11 INFO Uploading batch count=231472026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=231482026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526834684/002/c31492026/10/01 08:24:11 INFO Uploading batch count=131502026/10/01 08:24:11 INFO Uploading batch count=131512026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=131522026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526834684/002/d31532026/10/01 08:24:11 INFO Uploading batch count=131542026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=131552026/10/01 08:24:11 INFO Uploading batch count=231562026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=231572026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526834684/002/e3158--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)31592026/10/01 08:24:11 INFO Uploading batch count=131602026/10/01 08:24:11 ERROR Upload failed error="upload failed" count=131612026/10/01 08:24:11 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2526834684/002/f31622026/10/01 08:24:11 ERROR Drain finished with paths left in queue remaining=131632026/10/01 08:24:11 ERROR Drain finished with paths left in queue remaining=103164--- PASS: TestDrainIsolatesPoisonPath (0.02s)3165--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3166--- PASS: TestWorkerUploadsAndRemoves (0.03s)3167--- PASS: TestWorkerSkipsGCdPaths (0.03s)3168--- PASS: TestWorkerPrunesClosureDeps (0.03s)3169--- PASS: TestQueueRemoveLargeClosure (0.07s)31702026/10/01 08:24:11 ERROR Upload failed error="context deadline exceeded" count=231712026/10/01 08:24:11 ERROR Drain finished with paths left in queue remaining=43172--- PASS: TestDrainTimeout (0.22s)3173--- PASS: TestQueueConcurrentWriters (0.28s)31742026/10/01 08:24:12 INFO Uploading batch count=131752026/10/01 08:24:12 INFO Uploading batch count=131762026/10/01 08:24:12 INFO Uploading batch count=131772026/10/01 08:24:12 ERROR Upload failed error="upload failed" count=131782026/10/01 08:24:12 INFO Uploading batch count=131792026/10/01 08:24:12 ERROR Upload failed error="upload failed" count=131802026/10/01 08:24:12 INFO Uploading batch count=131812026/10/01 08:24:12 ERROR Upload failed error="upload failed" count=131822026/10/01 08:24:12 INFO Uploading batch count=131832026/10/01 08:24:12 ERROR Upload failed error="upload failed" count=131842026/10/01 08:24:12 ERROR Drain finished with paths left in queue remaining=13185--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3186PASS