niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #308
· 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 TestStreamPushBatchesUnderLoad97=== CONT TestFileTokenReadsAndCaches98=== CONT TestScriptTokenCachesUntilRefresh99=== CONT TestScriptTokenNoExpiryRerunsEveryCall100=== CONT TestFileTokenEmpty101=== CONT TestScriptTokenEmptyToken102=== CONT TestFileTokenMissing103=== CONT TestClientSignaturesByStorePath104=== CONT TestStaticToken105=== CONT TestScriptTokenBadJSON106=== CONT TestSetClientTLSErrors107=== CONT TestPathInfoHashCompatibility108=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)109=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)110=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon111=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon112=== CONT TestResolveStorePath113=== CONT TestStreamPushReportsSignatures114=== CONT TestSetClientTLS115=== CONT TestGetStorePathHash116=== RUN TestGetStorePathHash/valid_store_path117=== PAUSE TestGetStorePathHash/valid_store_path118=== CONT TestScriptTokenEmptyCommand119=== CONT TestStreamPushReportsEveryPath120=== CONT TestRateLimiterFeedback121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122=== CONT TestPathInfoCACompatibility123=== CONT TestShellSplitErrors124=== CONT TestParsePathInfoJSONMultiplePaths125=== CONT TestShellSplit126=== CONT TestParsePathInfoJSON127--- PASS: TestFileTokenReadsAndCaches (0.00s)128=== CONT TestDoWithRetry_BodyReplayedViaGetBody129=== CONT TestStreamPushRequestLine130--- PASS: TestStaticToken (0.00s)131--- PASS: TestClientSignaturesByStorePath (0.00s)132--- PASS: TestFileTokenEmpty (0.00s)1332026/10/01 09:27:23 WARN Rate limiter enabled after throttle name=server-test rate=5134=== CONT TestEncodeNixBase32135=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1362026/10/01 09:27:23 ERROR Upload failed error=boom count=11372026/10/01 09:27:23 ERROR Upload failed error=boom count=1138=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI139=== CONT TestDumpPathMatchesNix140=== CONT TestUploadMultipart_PartsInParallel141=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI142=== RUN TestGetStorePathHash/basename_without_hyphen_should_error143=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths144=== RUN TestPathInfoCACompatibility/null_ca_field145=== RUN TestParsePathInfoJSON/Nix_format146--- PASS: TestFileTokenMissing (0.00s)147=== CONT TestConvertHashToNix32148=== RUN TestConvertHashToNix32/SRI_format_to_Nix32149=== CONT TestDumpPathSingleFile150=== CONT TestDumpPathWriterError151--- PASS: TestScriptTokenEmptyCommand (0.00s)152--- PASS: TestShellSplitErrors (0.00s)153--- PASS: TestShellSplit (0.00s)154=== RUN TestEncodeNixBase32/test_string_hash155=== CONT TestEncodeNixBase32WithRealHash156=== CONT TestStreamPushGivesUpOnDeadServer157=== CONT TestStreamPushIsolatesFailures1582026/10/01 09:27:23 WARN Rate limiter enabled after throttle name=server-test rate=51592026/10/01 09:27:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43625160=== RUN TestRateLimiterFeedback/429_enables_limiter161=== PAUSE TestRateLimiterFeedback/429_enables_limiter1622026/10/01 09:27:23 ERROR Upload failed error="connection refused" count=20163=== PAUSE TestPathInfoCACompatibility/null_ca_field1642026/10/01 09:27:23 ERROR Server seems unavailable, giving up on batch untried=17165--- PASS: TestScriptTokenBadJSON (0.00s)166=== RUN TestSetClientTLSErrors/missing_cert_file167=== RUN TestSetClientTLS/rejects_connection_without_client_cert1682026/10/01 09:27:23 ERROR Upload failed error="bad path" count=3169=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32170=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert1712026/10/01 09:27:23 WARN Rate limiter backed off name=server-test rate=5172=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA1732026/10/01 09:27:23 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43625174=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths175=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512177=== PAUSE TestEncodeNixBase32/test_string_hash178=== CONT TestFilterOversizedClosures179=== RUN TestFilterOversizedClosures/no_limit_keeps_everything180=== RUN TestEncodeNixBase32/empty_input181=== PAUSE TestEncodeNixBase32/empty_input182=== CONT TestPartSizeForNAR183=== RUN TestPartSizeForNAR/zero_stays_at_minimum184=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error187=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error188=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error189=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512190=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon191=== CONT TestEncodeNixBase32/test_string_hash192=== CONT TestEncodeNixBase32/empty_input193=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error194=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error195=== CONT TestGetStorePathHash/valid_store_path196=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error197--- PASS: TestResolveStorePath (0.00s)198--- PASS: TestScriptTokenEmptyToken (0.01s)199--- PASS: TestStreamPushReportsEveryPath (0.00s)200--- PASS: TestStreamPushReportsSignatures (0.00s)201--- PASS: TestDoServerRequestAttachesToken (0.01s)202=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error203=== RUN TestPathInfoCACompatibility/old_string_format_-_text204=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text205=== CONT TestUploadMultipart_SupersededByPeer206=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive207=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive208=== RUN TestPathInfoCACompatibility/new_structured_format_-_text209=== RUN TestUploadMultipart_SupersededByPeer/exists210=== PAUSE TestUploadMultipart_SupersededByPeer/exists211=== RUN TestUploadMultipart_SupersededByPeer/missing212=== PAUSE TestUploadMultipart_SupersededByPeer/missing213=== CONT TestUploadMultipart_SupersededByPeer/exists214=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text215=== RUN TestConvertHashToNix32/already_Nix32_format216=== PAUSE TestConvertHashToNix32/already_Nix32_format217=== CONT TestCaseHackSuffix218=== CONT TestRegisterUploadedObjectReusesConnections219=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA220=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths221=== PAUSE TestParsePathInfoJSON/Nix_format222=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything223=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths224=== RUN TestParsePathInfoJSON/Lix_format225=== PAUSE TestParsePathInfoJSON/Lix_format226=== RUN TestParsePathInfoJSON/empty_input227=== PAUSE TestParsePathInfoJSON/empty_input228=== RUN TestParsePathInfoJSON/whitespace_only229=== PAUSE TestParsePathInfoJSON/whitespace_only230=== RUN TestParsePathInfoJSON/invalid_JSON231=== PAUSE TestParsePathInfoJSON/invalid_JSON232=== CONT TestParsePathInfoJSON/Nix_format233=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped235=== RUN TestFilterOversizedClosures/all_closures_skipped236=== PAUSE TestFilterOversizedClosures/all_closures_skipped237=== CONT TestFilterOversizedClosures/no_limit_keeps_everything238=== CONT TestParsePathInfoJSON/invalid_JSON239=== CONT TestParsePathInfoJSON/whitespace_only240=== CONT TestParsePathInfoJSON/empty_input241=== CONT TestParsePathInfoJSON/Lix_format242=== CONT TestFilterOversizedClosures/all_closures_skipped243=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2442026/10/01 09:27:23 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=502452026/10/01 09:27:23 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=2000246=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum247=== RUN TestPartSizeForNAR/small_stays_at_minimum248=== PAUSE TestPartSizeForNAR/small_stays_at_minimum249=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum250=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum251=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts252=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts253=== RUN TestPartSizeForNAR/1_TiB254=== PAUSE TestPartSizeForNAR/1_TiB255=== RUN TestPartSizeForNAR/5_TiB_S3_max_object256=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object257=== RUN TestPartSizeForNAR/capped_at_5_GiB258=== PAUSE TestPartSizeForNAR/capped_at_5_GiB259=== CONT TestPartSizeForNAR/zero_stays_at_minimum260=== RUN TestRateLimiterFeedback/503_enables_limiter261=== PAUSE TestRateLimiterFeedback/503_enables_limiter262=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter263=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter264=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter265=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter266=== CONT TestRateLimiterFeedback/429_enables_limiter267=== CONT TestPartSizeForNAR/capped_at_5_GiB268=== CONT TestPartSizeForNAR/5_TiB_S3_max_object269=== CONT TestPartSizeForNAR/1_TiB270=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts271=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum272=== CONT TestPartSizeForNAR/small_stays_at_minimum273=== CONT TestGetStorePathHash/basename_without_hyphen_should_error274--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)275--- PASS: TestEncodeNixBase32WithRealHash (0.00s)276--- PASS: TestStreamPushIsolatesFailures (0.00s)277--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)278--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)279=== CONT TestRateLimiterFeedback/503_enables_limiter280=== PAUSE TestSetClientTLSErrors/missing_cert_file281=== RUN TestSetClientTLSErrors/missing_key_file282=== PAUSE TestSetClientTLSErrors/missing_key_file2832026/10/01 09:27:23 WARN Rate limiter enabled after throttle name=server-test rate=5284=== RUN TestSetClientTLSErrors/missing_ca_file285=== CONT TestUploadMultipart_SupersededByPeer/missing2862026/10/01 09:27:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42197287=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method288--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)289=== RUN TestConvertHashToNix32/invalid_format290=== PAUSE TestConvertHashToNix32/invalid_format291=== CONT TestConvertHashToNix32/SRI_format_to_Nix32292=== CONT TestScriptTokenScriptFails2932026/10/01 09:27:23 WARN Rate limiter backed off name=server-test rate=5294=== CONT TestConvertHashToNix32/invalid_format295=== CONT TestConvertHashToNix32/already_Nix32_format2962026/10/01 09:27:23 WARN Rate limiter enabled after throttle name=server-test rate=52972026/10/01 09:27:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:394172982026/10/01 09:27:23 WARN Rate limiter backed off name=server-test rate=5299=== RUN TestSetClientTLS/preserves_debug_logging_transport300=== PAUSE TestSetClientTLS/preserves_debug_logging_transport301=== CONT TestSetClientTLS/rejects_connection_without_client_cert302=== CONT TestSetClientTLS/preserves_debug_logging_transport303=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths304=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths305=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter306=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter307=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA308=== PAUSE TestSetClientTLSErrors/missing_ca_file309=== RUN TestSetClientTLSErrors/invalid_ca_file310=== PAUSE TestSetClientTLSErrors/invalid_ca_file311--- PASS: TestPathInfoHashCompatibility (0.03s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)315 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)316--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)317=== CONT TestSetClientTLSErrors/missing_cert_file318=== CONT TestSetClientTLSErrors/invalid_ca_file319=== CONT TestSetClientTLSErrors/missing_ca_file320=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method321=== CONT TestPathInfoCACompatibility/null_ca_field322=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive323=== CONT TestPathInfoCACompatibility/new_structured_format_-_text324=== CONT TestPathInfoCACompatibility/old_string_format_-_text325--- PASS: TestParsePathInfoJSON (0.03s)326 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)327 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)328 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)329 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)330 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)331--- PASS: TestEncodeNixBase32 (0.03s)332 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)333 --- PASS: TestEncodeNixBase32/empty_input (0.00s)334--- PASS: TestFilterOversizedClosures (0.00s)335 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)336 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)337 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)338--- PASS: TestGetStorePathHash (0.03s)339 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)340 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)341 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)342 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)343=== CONT TestSetClientTLSErrors/missing_key_file344=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method345--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)347 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)348--- PASS: TestConvertHashToNix32 (0.03s)349 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)350 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)351 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)352--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)353 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)354 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)355--- PASS: TestPartSizeForNAR (0.00s)356 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)357 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)358 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)359 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)360 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)361 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)363--- PASS: TestRateLimiterFeedback (0.04s)364 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)365 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)366 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)368--- PASS: TestScriptTokenScriptFails (0.01s)369--- PASS: TestPathInfoCACompatibility (0.04s)370 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)371 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)372 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)373 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)374 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)375--- PASS: TestSetClientTLSErrors (0.04s)376 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)377 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3802026/10/01 09:27:23 http: TLS handshake error from 127.0.0.1:40374: remote error: tls: bad certificate381--- PASS: TestStreamPushRequestLine (0.05s)382--- PASS: TestSetClientTLS (0.04s)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: TestRegisterUploadedObjectReusesConnections (0.03s)387--- PASS: TestCaseHackSuffix (0.03s)388--- PASS: TestDumpPathSingleFile (0.07s)389--- PASS: TestDumpPathWriterError (0.05s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.64s)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/postgres1086629327/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/postgres1086629327/data -l logfile start422423/build/postgres1086629327:5432 - no response4242026-10-01 09:27:24.896 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 09:27:24.897 UTC [129] LOG: listening on Unix socket "/build/postgres1086629327/.s.PGSQL.5432"4262026-10-01 09:27:24.902 UTC [136] LOG: database system was shut down at 2026-10-01 09:27:24 UTC4272026-10-01 09:27:24.906 UTC [129] LOG: database system is ready to accept connections428/build/postgres1086629327:5432 - accepting connections429{"timestamp":"2026-10-01T09:27:25.200488244Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"cd9a1ce4-131a-4822-885a-a2219e1d36be","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(386)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 09:27:25.391 UTC [563] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 09:27:25.391 UTC [563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 09:27:25 OK 20241026095416_initial_model.sql (6.95ms)4762026/10/01 09:27:25 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)4772026/10/01 09:27:25 OK 20251218171726_add_pins.sql (1.98ms)4782026/10/01 09:27:25 OK 20260628120000_add_object_size_and_stats.sql (1.83ms)4792026/10/01 09:27:25 OK 20260905000000_add_claims.sql (2.11ms)4802026/10/01 09:27:25 OK 20260920000000_drop_claims.sql (1.33ms)4812026/10/01 09:27:25 OK 20260923120000_add_pushes.sql (998.95µs)4822026/10/01 09:27:25 goose: successfully migrated database to version: 202609231200004832026/10/01 09:27:25 OK 1_commit_pending_closure.sql (1.39ms)4842026/10/01 09:27:25 OK 2_object_stats_trigger.sql (715.55µs)4852026/10/01 09:27:25 OK 3_commit_push.sql (575.79µs)4862026/10/01 09:27:25 goose: up to current file version: 34872026/10/01 09:27:25 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 09:27:26 INFO lead: released remote=192.0.2.1:12344892026/10/01 09:27:26 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 09:27:26 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 09:27:26.156 UTC [573] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 09:27:26.156 UTC [573] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 09:27:26 OK 20241026095416_initial_model.sql (6.55ms)4982026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)4992026/10/01 09:27:26 OK 20251218171726_add_pins.sql (2.16ms)5002026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (2.44ms)5012026/10/01 09:27:26 OK 20260905000000_add_claims.sql (2.29ms)5022026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (1.51ms)5032026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (1.08ms)5042026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200005052026/10/01 09:27:26 OK 1_commit_pending_closure.sql (1.64ms)5062026/10/01 09:27:26 OK 2_object_stats_trigger.sql (751.49µs)5072026/10/01 09:27:26 OK 3_commit_push.sql (700.28µs)5082026/10/01 09:27:26 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestObjectStatsTrigger581=== PAUSE TestObjectStatsTrigger582=== RUN TestOrphanedObjectsGC583=== PAUSE TestOrphanedObjectsGC584=== RUN TestOrphanedObjectsGCStressTest585=== PAUSE TestOrphanedObjectsGCStressTest586=== RUN TestCreatePin_ReservedPins587=== PAUSE TestCreatePin_ReservedPins588=== RUN TestPresentReportsOnlyClosureRoots589=== PAUSE TestPresentReportsOnlyClosureRoots590=== RUN TestParseSingleRange591=== PAUSE TestParseSingleRange592=== RUN TestProxyHeadersOnlyTrustedOnSocket593=== PAUSE TestProxyHeadersOnlyTrustedOnSocket594=== RUN TestIsValidCachePath595=== PAUSE TestIsValidCachePath596=== RUN TestReadProxyNarinfo597=== PAUSE TestReadProxyNarinfo598=== RUN TestReadProxyNarinfoAlreadyDecompressed599=== PAUSE TestReadProxyNarinfoAlreadyDecompressed600=== RUN TestReadProxyNarStreaming601=== PAUSE TestReadProxyNarStreaming602=== RUN TestReadProxy404603=== PAUSE TestReadProxy404604=== RUN TestReadProxyInvalidPath605=== PAUSE TestReadProxyInvalidPath606=== RUN TestReadProxyHead607=== PAUSE TestReadProxyHead608=== RUN TestReadProxyConditionalGet609=== PAUSE TestReadProxyConditionalGet610=== RUN TestReadProxyRootRedirectsToIndexHTML611=== PAUSE TestReadProxyRootRedirectsToIndexHTML612=== RUN TestReadProxyDisabled613=== PAUSE TestReadProxyDisabled614=== RUN TestReadRedirectNar615=== PAUSE TestReadRedirectNar616=== RUN TestReadRedirectKeepsNarinfoProxied617=== PAUSE TestReadRedirectKeepsNarinfoProxied618=== RUN TestReadProxyRangeRequest619=== PAUSE TestReadProxyRangeRequest620=== RUN TestReadRedirectUsesPublicS3URL621=== PAUSE TestReadRedirectUsesPublicS3URL622=== RUN TestPush_OverlappingRootsStoreOneRowPerKey623=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey624=== RUN TestPush_CompleteCommitsEveryRoot625=== PAUSE TestPush_CompleteCommitsEveryRoot626=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit627=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit628=== RUN TestPush_RejectsBadRequests629=== PAUSE TestPush_RejectsBadRequests630=== RUN TestPush_SignsNarinfosOfItsPendingObjects631=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects632=== RUN TestRedundantMultipartUpload633=== PAUSE TestRedundantMultipartUpload634=== RUN TestCompleteMultipartUpload_ErrorButObjectExists635=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists636=== RUN TestCompletedNarNotReofferedAcrossClosures637=== PAUSE TestCompletedNarNotReofferedAcrossClosures638=== RUN TestPresignedUploadRegisteredBeforeCommit639=== PAUSE TestPresignedUploadRegisteredBeforeCommit640=== RUN TestService_Rustfstest641=== PAUSE TestService_Rustfstest642=== RUN TestParseSize643=== PAUSE TestParseSize644=== RUN TestSkippedUploadsHandler645=== PAUSE TestSkippedUploadsHandler646=== RUN TestSystemdListenerNotActivated647--- PASS: TestSystemdListenerNotActivated (0.00s)648=== RUN TestWatchdogBeatsWhenHealthy649--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)650=== RUN TestWatchdogSkipsWhenUnhealthy6512026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 09:27:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"661--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)662=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle663=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle664=== RUN TestProxyWriteTimeout665=== PAUSE TestProxyWriteTimeout666=== RUN TestIsValidUploadKey667=== PAUSE TestIsValidUploadKey668=== RUN TestUploadHandlersRejectInvalidKeys669=== PAUSE TestUploadHandlersRejectInvalidKeys670=== RUN TestUploadHandlersRejectOversizedBody671=== PAUSE TestUploadHandlersRejectOversizedBody672=== RUN TestService_cleanupPendingClosuresHandler673=== PAUSE TestService_cleanupPendingClosuresHandler674=== RUN TestService_createPendingClosureHandler675=== PAUSE TestService_createPendingClosureHandler676=== RUN TestService_verifyS3Integrity677=== PAUSE TestService_verifyS3Integrity678=== RUN TestCompleteMultipartUnregistered679=== PAUSE TestCompleteMultipartUnregistered680=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT681=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT682=== CONT TestService_AuthMiddleware683=== CONT TestPresentReportsOnlyClosureRoots684=== CONT TestPush_RejectsBadRequests685=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT686=== CONT TestCompleteMultipartUnregistered687=== CONT TestService_verifyS3Integrity688=== CONT TestService_createPendingClosureHandler689=== CONT TestService_cleanupPendingClosuresHandler690=== CONT TestUploadHandlersRejectOversizedBody691=== CONT TestUploadHandlersRejectInvalidKeys692=== CONT TestIsValidUploadKey693=== CONT TestReadProxyConditionalGet694=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit695=== RUN TestIsValidUploadKey/narinfo696=== CONT TestPush_CompleteCommitsEveryRoot697=== CONT TestPush_OverlappingRootsStoreOneRowPerKey698=== CONT TestReadRedirectUsesPublicS3URL699=== CONT TestReadProxyRangeRequest700=== CONT TestReadRedirectKeepsNarinfoProxied701=== CONT TestReadRedirectNar702=== CONT TestReadProxyDisabled703=== CONT TestReadProxyRootRedirectsToIndexHTML704=== CONT TestFailedS3DeleteKeepsTombstone705=== CONT TestCreatePin_ReservedPins706=== CONT TestProxyWriteTimeout707=== RUN TestProxyWriteTimeout/narinfo708=== PAUSE TestProxyWriteTimeout/narinfo709=== RUN TestProxyWriteTimeout/1_GiB_nar710=== PAUSE TestProxyWriteTimeout/1_GiB_nar711=== RUN TestProxyWriteTimeout/10_GiB_nar712=== PAUSE TestProxyWriteTimeout/10_GiB_nar713=== RUN TestProxyWriteTimeout/unknown_size714=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info715=== PAUSE TestIsValidUploadKey/narinfo716=== RUN TestIsValidUploadKey/nar_zst717=== PAUSE TestProxyWriteTimeout/unknown_size718=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info719=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal720=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal721=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key722=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key723=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key724=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key725=== CONT TestOrphanedObjectsGC726=== PAUSE TestIsValidUploadKey/nar_zst727=== CONT TestOrphanedObjectsGCStressTest7282026/10/01 09:27:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44341/oidc729=== RUN TestIsValidUploadKey/nar_xz730=== PAUSE TestIsValidUploadKey/nar_xz731=== RUN TestIsValidUploadKey/nar_plain732=== PAUSE TestIsValidUploadKey/nar_plain733=== RUN TestIsValidUploadKey/listing734=== PAUSE TestIsValidUploadKey/listing735=== RUN TestIsValidUploadKey/build_log736=== PAUSE TestIsValidUploadKey/build_log737=== RUN TestIsValidUploadKey/build_log_home-manager_file738=== PAUSE TestIsValidUploadKey/build_log_home-manager_file739=== RUN TestIsValidUploadKey/build_log_plus_in_name740=== PAUSE TestIsValidUploadKey/build_log_plus_in_name741=== RUN TestIsValidUploadKey/build_log_question_mark742=== PAUSE TestIsValidUploadKey/build_log_question_mark743=== RUN TestIsValidUploadKey/build_log_equals744=== PAUSE TestIsValidUploadKey/build_log_equals745=== RUN TestIsValidUploadKey/realisation746=== PAUSE TestIsValidUploadKey/realisation747=== RUN TestIsValidUploadKey/realisation_plus_in_output748=== PAUSE TestIsValidUploadKey/realisation_plus_in_output749=== RUN TestIsValidUploadKey/nix-cache-info750=== PAUSE TestIsValidUploadKey/nix-cache-info751=== RUN TestIsValidUploadKey/index.html752=== PAUSE TestIsValidUploadKey/index.html753=== RUN TestIsValidUploadKey/narinfo_key,_nar_type754=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type755=== RUN TestIsValidUploadKey/nar_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type757=== RUN TestIsValidUploadKey/listing_key,_narinfo_type758=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type759=== RUN TestIsValidUploadKey/traversal760=== PAUSE TestIsValidUploadKey/traversal761=== RUN TestIsValidUploadKey/traversal_nar762=== PAUSE TestIsValidUploadKey/traversal_nar763=== RUN TestIsValidUploadKey/absolute764=== PAUSE TestIsValidUploadKey/absolute765=== RUN TestIsValidUploadKey/empty_key766=== PAUSE TestIsValidUploadKey/empty_key767=== RUN TestIsValidUploadKey/unknown_type768=== PAUSE TestIsValidUploadKey/unknown_type769=== CONT TestObjectStatsTrigger7702026-10-01 09:27:26.580 UTC [637] ERROR: relation "goose_db_version" does not exist at character 367712026-10-01 09:27:26.580 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC772=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure773=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure774=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart775=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart776=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts777=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts778=== CONT TestMultipartCleanup7792026-10-01 09:27:26.614 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367802026-10-01 09:27:26.614 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026/10/01 09:27:26 OK 20241026095416_initial_model.sql (177.03ms)7822026/10/01 09:27:26 OK 20241026095416_initial_model.sql (167.02ms)7832026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (5.86ms)7842026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (5.92ms)7852026-10-01 09:27:26.827 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367862026-10-01 09:27:26.827 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026-10-01 09:27:26.828 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367882026-10-01 09:27:26.828 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-10-01 09:27:26.830 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367902026-10-01 09:27:26.830 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/10/01 09:27:26 OK 20251218171726_add_pins.sql (25.21ms)7922026/10/01 09:27:26 OK 20251218171726_add_pins.sql (23.31ms)7932026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (9.85ms)7942026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (11.21ms)7952026-10-01 09:27:26.856 UTC [656] ERROR: relation "goose_db_version" does not exist at character 367962026-10-01 09:27:26.856 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-10-01 09:27:26.857 UTC [655] ERROR: relation "goose_db_version" does not exist at character 367982026-10-01 09:27:26.857 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-10-01 09:27:26.857 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368002026-10-01 09:27:26.857 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026-10-01 09:27:26.857 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368022026-10-01 09:27:26.857 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026-10-01 09:27:26.857 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368042026-10-01 09:27:26.857 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026/10/01 09:27:26 OK 20260905000000_add_claims.sql (11.46ms)8062026/10/01 09:27:26 OK 20260905000000_add_claims.sql (14.19ms)8072026/10/01 09:27:26 OK 20241026095416_initial_model.sql (17.49ms)8082026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)8092026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (5.91ms)8102026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (6.05ms)8112026/10/01 09:27:26 OK 20251218171726_add_pins.sql (7.2ms)8122026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (4.35ms)8132026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200008142026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (3.8ms)8152026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200008162026/10/01 09:27:26 OK 20241026095416_initial_model.sql (23.82ms)8172026-10-01 09:27:26.882 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368182026-10-01 09:27:26.882 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026-10-01 09:27:26.887 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368202026-10-01 09:27:26.887 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/10/01 09:27:26 OK 1_commit_pending_closure.sql (18.94ms)8222026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (24.28ms)8232026/10/01 09:27:26 OK 1_commit_pending_closure.sql (21.95ms)8242026/10/01 09:27:26 OK 20241026095416_initial_model.sql (21.89ms)8252026/10/01 09:27:26 OK 20241026095416_initial_model.sql (43.58ms)8262026/10/01 09:27:26 OK 20241026095416_initial_model.sql (23.06ms)8272026/10/01 09:27:26 OK 20241026095416_initial_model.sql (22.24ms)8282026/10/01 09:27:26 OK 20241026095416_initial_model.sql (22.05ms)8292026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (20.14ms)8302026/10/01 09:27:26 OK 20241026095416_initial_model.sql (21.57ms)8312026/10/01 09:27:26 OK 2_object_stats_trigger.sql (5.57ms)8322026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.85ms)8332026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)8342026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)8352026/10/01 09:27:26 OK 3_commit_push.sql (2.61ms)8362026/10/01 09:27:26 goose: up to current file version: 38372026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.64ms)8382026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.68ms)8392026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (4.02ms)8402026/10/01 09:27:26 OK 3_commit_push.sql (2.49ms)8412026/10/01 09:27:26 goose: up to current file version: 38422026/10/01 09:27:26 OK 20251218171726_add_pins.sql (4.28ms)8432026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)8442026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (4.34ms)8452026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.33ms)8462026/10/01 09:27:26 OK 20251218171726_add_pins.sql (5.19ms)8472026/10/01 09:27:26 OK 20251218171726_add_pins.sql (5.49ms)8482026-10-01 09:27:26.910 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368492026-10-01 09:27:26.910 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/10/01 09:27:26 OK 20251218171726_add_pins.sql (5.25ms)8512026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (3.07ms)8522026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200008532026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (6.64ms)8542026/10/01 09:27:26 OK 20251218171726_add_pins.sql (7.14ms)8552026/10/01 09:27:26 OK 20241026095416_initial_model.sql (11.5ms)8562026/10/01 09:27:26 OK 20251218171726_add_pins.sql (6.54ms)8572026-10-01 09:27:26.913 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368582026-10-01 09:27:26.913 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/10/01 09:27:26 OK 20251218171726_add_pins.sql (7.64ms)8602026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.18ms)8612026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.1ms)8622026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)8632026-10-01 09:27:26.915 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368642026-10-01 09:27:26.915 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026-10-01 09:27:26.916 UTC [662] ERROR: relation "goose_db_version" does not exist at character 368662026-10-01 09:27:26.916 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8672026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.81ms)8682026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)8692026-10-01 09:27:26.917 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368702026-10-01 09:27:26.917 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8712026/10/01 09:27:26 OK 20260905000000_add_claims.sql (5.16ms)8722026/10/01 09:27:26 OK 20241026095416_initial_model.sql (14ms)8732026-10-01 09:27:26.918 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368742026-10-01 09:27:26.918 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.69ms)8762026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)8772026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (6.4ms)8782026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.12ms)8792026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.17ms)8802026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.55ms)8812026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (6.28ms)8822026/10/01 09:27:26 OK 20251218171726_add_pins.sql (4.93ms)8832026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.6ms)8842026/10/01 09:27:26 OK 3_commit_push.sql (1.76ms)8852026-10-01 09:27:26.920 UTC [665] ERROR: relation "goose_db_version" does not exist at character 368862026-10-01 09:27:26.920 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8872026/10/01 09:27:26 goose: up to current file version: 38882026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)8892026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.65ms)8902026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.89ms)8912026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.18ms)8922026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.52ms)8932026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200008942026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.01ms)8952026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.31ms)8962026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.14ms)8972026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.27ms)8982026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200008992026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.82ms)9002026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)9012026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.9ms)9022026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009032026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.94ms)9042026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009052026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.32ms)9062026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.73ms)9072026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.42ms)9082026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.38ms)9092026/10/01 09:27:26 OK 1_commit_pending_closure.sql (2.95ms)9102026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.09ms)9112026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.88ms)9122026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.31ms)9132026/10/01 09:27:26 OK 20241026095416_initial_model.sql (11.15ms)9142026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.72ms)9152026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.02ms)9162026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.94ms)9172026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009182026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (3.29ms)9192026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009202026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.47ms)9212026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009222026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)9232026/10/01 09:27:26 OK 3_commit_push.sql (1.34ms)9242026/10/01 09:27:26 goose: up to current file version: 39252026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.6ms)9262026/10/01 09:27:26 OK 3_commit_push.sql (1.6ms)9272026/10/01 09:27:26 goose: up to current file version: 39282026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.05ms)9292026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)9302026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.04ms)9312026/10/01 09:27:26 OK 3_commit_push.sql (1.54ms)9322026/10/01 09:27:26 goose: up to current file version: 39332026-10-01 09:27:26.934 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369342026-10-01 09:27:26.934 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026/10/01 09:27:26 OK 3_commit_push.sql (1.81ms)9362026/10/01 09:27:26 goose: up to current file version: 39372026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.6ms)9382026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.46ms)9392026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.28ms)9402026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.65ms)9412026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009422026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.49ms)9432026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.88ms)9442026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.86ms)9452026/10/01 09:27:26 OK 20241026095416_initial_model.sql (10.57ms)9462026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.08ms)9472026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.87ms)9482026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.1ms)9492026/10/01 09:27:26 OK 3_commit_push.sql (1.2ms)9502026/10/01 09:27:26 goose: up to current file version: 39512026/10/01 09:27:26 OK 1_commit_pending_closure.sql (2.41ms)9522026/10/01 09:27:26 OK 3_commit_push.sql (1.56ms)9532026/10/01 09:27:26 goose: up to current file version: 39542026/10/01 09:27:26 OK 3_commit_push.sql (1.87ms)9552026/10/01 09:27:26 goose: up to current file version: 39562026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)9572026-10-01 09:27:26.939 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369582026-10-01 09:27:26.939 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9592026/10/01 09:27:26 OK 20241026095416_initial_model.sql (10.74ms)9602026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.68ms)9612026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)9622026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (3.13ms)9632026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009642026/10/01 09:27:26 OK 20241026095416_initial_model.sql (12.07ms)9652026-10-01 09:27:26.942 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369662026-10-01 09:27:26.942 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/10/01 09:27:26 OK 3_commit_push.sql (1.52ms)9682026/10/01 09:27:26 goose: up to current file version: 39692026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)9702026-10-01 09:27:26.943 UTC [669] ERROR: relation "goose_db_version" does not exist at character 369712026-10-01 09:27:26.943 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9722026/10/01 09:27:26 OK 20251218171726_add_pins.sql (4.22ms)9732026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.36ms)9742026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)9752026/10/01 09:27:26 OK 1_commit_pending_closure.sql (4.25ms)9762026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.93ms)9772026/10/01 09:27:26 OK 20241026095416_initial_model.sql (13.02ms)9782026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.68ms)9792026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.81ms)9802026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)9812026/10/01 09:27:26 OK 20241026095416_initial_model.sql (15.94ms)9822026/10/01 09:27:26 OK 20241026095416_initial_model.sql (12.02ms)9832026/10/01 09:27:26 OK 3_commit_push.sql (1.97ms)9842026-10-01 09:27:26.949 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369852026-10-01 09:27:26.949 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9862026/10/01 09:27:26 goose: up to current file version: 39872026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)9882026/10/01 09:27:26 OK 20251218171726_add_pins.sql (5.2ms)9892026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (3.57ms)9902026/10/01 09:27:26 goose: successfully migrated database to version: 202609231200009912026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)9922026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)993--- PASS: TestPresentReportsOnlyClosureRoots (0.51s)994=== CONT TestServerTLSConfig995=== RUN TestServerTLSConfig/no_client_CA996=== PAUSE TestServerTLSConfig/no_client_CA997=== RUN TestServerTLSConfig/missing_CA_file998=== PAUSE TestServerTLSConfig/missing_CA_file9992026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.48ms)1000=== RUN TestServerTLSConfig/not_a_PEM_file10012026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)1002=== PAUSE TestServerTLSConfig/not_a_PEM_file10032026/10/01 09:27:26 OK 20241026095416_initial_model.sql (9.8ms)1004=== CONT TestService_NativeMTLS10052026/10/01 09:27:26 OK 1_commit_pending_closure.sql (1.86ms)10062026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.86ms)10072026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)10082026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.25ms)10092026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.51ms)10102026/10/01 09:27:26 OK 20251218171726_add_pins.sql (4.19ms)10112026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.26ms)10122026/10/01 09:27:26 OK 20251218171726_add_pins.sql (4.37ms)10132026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.51ms)10142026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (1.71ms)10152026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010162026/10/01 09:27:26 OK 3_commit_push.sql (1.42ms)10172026/10/01 09:27:26 goose: up to current file version: 310182026/10/01 09:27:26 OK 20241026095416_initial_model.sql (9.26ms)10192026/10/01 09:27:26 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1020--- PASS: TestService_AuthMiddleware (0.52s)1021=== CONT TestMetricsInventory10222026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.25ms)10232026/10/01 09:27:26 OK 20241026095416_initial_model.sql (9.35ms)10242026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)10252026/10/01 09:27:26 OK 20241026095416_initial_model.sql (9.43ms)10262026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.93ms)10272026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)10282026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.8ms)10292026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)10302026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.45ms)10312026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (1.73ms)10322026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010332026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)10342026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)10352026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (2ms)10362026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)10372026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.54ms)10382026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.37ms)10392026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.32ms)10402026/10/01 09:27:26 OK 20251218171726_add_pins.sql (2.75ms)10412026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.93ms)10422026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.04ms)10432026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.02ms)10442026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.06ms)10452026/10/01 09:27:26 OK 20241026095416_initial_model.sql (9.18ms)10462026/10/01 09:27:26 OK 3_commit_push.sql (2.35ms)10472026/10/01 09:27:26 goose: up to current file version: 310482026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.17ms)10492026/10/01 09:27:26 OK 20260905000000_add_claims.sql (4.14ms)10502026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)10512026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.53ms)10522026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.37ms)10532026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010542026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.15ms)10552026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)10562026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.51ms)10572026/10/01 09:27:26 OK 3_commit_push.sql (2.15ms)10582026/10/01 09:27:26 goose: up to current file version: 310592026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)10602026/10/01 09:27:26 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)10612026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.18ms)10622026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.12ms)10632026/10/01 09:27:26 OK 20260905000000_add_claims.sql (2.6ms)10642026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.06ms)10652026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.65ms)10662026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010672026/10/01 09:27:26 OK 1_commit_pending_closure.sql (2.73ms)10682026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (1.65ms)10692026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010702026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.12ms)10712026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.86ms)10722026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010732026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.22ms)10742026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.81ms)10752026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010762026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.37ms)10772026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (3.26ms)10782026/10/01 09:27:26 OK 20251218171726_add_pins.sql (3.29ms)10792026/10/01 09:27:26 OK 1_commit_pending_closure.sql (2.82ms)10802026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.19ms)10812026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010822026/10/01 09:27:26 OK 1_commit_pending_closure.sql (4.11ms)10832026/10/01 09:27:26 OK 3_commit_push.sql (2.19ms)10842026/10/01 09:27:26 goose: up to current file version: 310852026/10/01 09:27:26 OK 1_commit_pending_closure.sql (2.34ms)10862026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.66ms)10872026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (2.54ms)10882026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.92ms)10892026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000010902026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.95ms)10912026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.13ms)10922026/10/01 09:27:26 OK 3_commit_push.sql (2.01ms)10932026/10/01 09:27:26 goose: up to current file version: 310942026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.16ms)10952026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.09ms)10962026/10/01 09:27:26 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)10972026/10/01 09:27:26 OK 3_commit_push.sql (2.2ms)10982026/10/01 09:27:26 goose: up to current file version: 310992026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (2.87ms)11002026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000011012026/10/01 09:27:26 INFO Received push request method=POST path=/api/pushes11022026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.19ms)11032026/10/01 09:27:26 OK 2_object_stats_trigger.sql (2.4ms)11042026/10/01 09:27:26 OK 1_commit_pending_closure.sql (3.7ms)11052026/10/01 09:27:26 OK 3_commit_push.sql (2.22ms)11062026/10/01 09:27:26 goose: up to current file version: 311072026/10/01 09:27:26 OK 3_commit_push.sql (2ms)11082026/10/01 09:27:26 goose: up to current file version: 311092026/10/01 09:27:26 OK 20260905000000_add_claims.sql (3.43ms)11102026/10/01 09:27:26 OK 3_commit_push.sql (1.56ms)11112026/10/01 09:27:26 goose: up to current file version: 311122026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.52ms)11132026/10/01 09:27:26 OK 1_commit_pending_closure.sql (2.66ms)11142026/10/01 09:27:26 OK 3_commit_push.sql (720.84µs)11152026/10/01 09:27:26 goose: up to current file version: 311162026/10/01 09:27:26 OK 20260920000000_drop_claims.sql (1.55ms)11172026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1ms)11182026/10/01 09:27:26 OK 3_commit_push.sql (627.55µs)11192026/10/01 09:27:26 goose: up to current file version: 311202026/10/01 09:27:26 OK 20260923120000_add_pushes.sql (1.23ms)11212026/10/01 09:27:26 goose: successfully migrated database to version: 2026092312000011222026/10/01 09:27:26 OK 1_commit_pending_closure.sql (1.88ms)11232026/10/01 09:27:26 OK 2_object_stats_trigger.sql (1.14ms)11242026/10/01 09:27:26 OK 3_commit_push.sql (1.3ms)11252026/10/01 09:27:26 goose: up to current file version: 311262026/10/01 09:27:27 INFO Received complete push request method=POST path=/api/pushes/1/complete11272026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures11282026/10/01 09:27:27 INFO Received push request method=POST path=/api/pushes1129--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.59s)1130=== CONT TestNARDeduplicationMetadataUploadBug11312026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures11322026-10-01 09:27:27.051 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611332026-10-01 09:27:27.051 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026-10-01 09:27:27.054 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3611352026-10-01 09:27:27.054 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026/10/01 09:27:27 OK 20241026095416_initial_model.sql (7.32ms)11372026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)11382026/10/01 09:27:27 OK 20241026095416_initial_model.sql (7.94ms)11392026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)11402026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.72ms)1141--- PASS: TestReadProxyConditionalGet (0.63s)1142=== CONT TestCreatePendingClosureRejectsOversizedNAR11432026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures1144--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1145=== CONT TestCacheConfigHandlerMaxNarSize1146--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1147=== CONT TestGenerateLandingPage11482026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.62ms)11492026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)11502026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.1ms)11512026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.44ms)1152--- PASS: TestGenerateLandingPage (0.00s)1153=== CONT TestService_readinessHandler11542026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.17ms)11552026/10/01 09:27:27 INFO Aborted multipart uploads count=011562026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.1ms)11572026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.33ms)11582026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000011592026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (1.43ms)11602026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.22ms)11612026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000011622026/10/01 09:27:27 OK 1_commit_pending_closure.sql (1.72ms)11632026/10/01 09:27:27 WARN Force mode enabled - objects will be deleted immediately without grace period11642026/10/01 09:27:27 OK 2_object_stats_trigger.sql (700.65µs)11652026/10/01 09:27:27 OK 1_commit_pending_closure.sql (1.12ms)11662026/10/01 09:27:27 OK 3_commit_push.sql (714.29µs)11672026/10/01 09:27:27 goose: up to current file version: 311682026/10/01 09:27:27 OK 2_object_stats_trigger.sql (723.01µs)11692026/10/01 09:27:27 OK 3_commit_push.sql (1.26ms)11702026/10/01 09:27:27 goose: up to current file version: 311712026/10/01 09:27:27 INFO Received push request method=POST path=/api/pushes11722026/10/01 09:27:27 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=011732026/10/01 09:27:27 INFO Vacuumed table table=pending_closures11742026/10/01 09:27:27 INFO Vacuumed table table=pending_objects11752026/10/01 09:27:27 INFO Vacuumed table table=multipart_uploads11762026/10/01 09:27:27 INFO Received cleanup request method=DELETE path=/api/pending_closures11772026/10/01 09:27:27 INFO Vacuumed table table=closures1178--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.67s)1179=== CONT TestService_healthCheckHandler11802026/10/01 09:27:27 INFO Vacuumed table table=objects11812026/10/01 09:27:27 INFO Aborted multipart uploads count=011822026/10/01 09:27:27 INFO Received complete push request method=POST path=/api/pushes/2/complete11832026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures1184--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.68s)1185=== CONT TestGracefulShutdownDrainsInflight11862026/10/01 09:27:27 INFO Starting HTTP server address=127.0.0.1:3296911872026/10/01 09:27:27 INFO Shutdown signal received, draining in-flight requests timeout=10s11882026/10/01 09:27:27 INFO Received cleanup request method=DELETE path=/api/pending_closures11892026/10/01 09:27:27 INFO Aborted multipart uploads count=111902026-10-01 09:27:27.136 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3611912026-10-01 09:27:27.136 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/10/01 09:27:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11932026-10-01 09:27:27.138 UTC [650] ERROR: Closure does not exist: id=111942026-10-01 09:27:27.138 UTC [650] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11952026-10-01 09:27:27.138 UTC [650] STATEMENT: -- name: CommitPendingClosure :exec1196 SELECT commit_pending_closure($1::bigint)1197 1198--- PASS: TestService_cleanupPendingClosuresHandler (0.70s)11992026/10/01 09:27:27 INFO Received push request method=POST path=/api/pushes1200=== CONT TestGCTaskStore_Fail1201--- PASS: TestGCTaskStore_Fail (0.00s)1202=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12032026/10/01 09:27:27 OK 20241026095416_initial_model.sql (10.56ms)12042026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)12052026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.73ms)12062026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)12072026/10/01 09:27:27 INFO Received complete push request method=POST path=/api/pushes/1/complete12082026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.36ms)12092026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (1.95ms)12102026/10/01 09:27:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12112026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.72ms)12122026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000012132026-10-01 09:27:27.171 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612142026-10-01 09:27:27.171 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12152026/10/01 09:27:27 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1216--- PASS: TestCompleteMultipartUnregistered (0.73s)1217=== CONT TestGCTaskStore_PhaseUpdates1218--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1219=== CONT TestSkippedUploadsHandler12202026/10/01 09:27:27 INFO Client skipped oversized paths paths=3 nar_bytes=500000000012212026/10/01 09:27:27 OK 1_commit_pending_closure.sql (11.35ms)1222--- PASS: TestSkippedUploadsHandler (0.01s)1223=== CONT TestGCTaskStore_CompletedAllowsNewTask1224--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1225=== CONT TestParseSize1226--- PASS: TestParseSize (0.00s)1227=== CONT TestGCTaskStore_GetReturnsLatest1228--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1229=== CONT TestService_Rustfstest1230--- PASS: TestPush_CompleteCommitsEveryRoot (0.74s)12312026/10/01 09:27:27 OK 2_object_stats_trigger.sql (3.53ms)1232=== CONT TestGCTaskStore_GetEmpty1233--- PASS: TestGCTaskStore_GetEmpty (0.00s)1234=== CONT TestPresignedUploadRegisteredBeforeCommit12352026/10/01 09:27:27 OK 3_commit_push.sql (1.22ms)12362026/10/01 09:27:27 goose: up to current file version: 312372026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.05ms)1238--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1239=== CONT TestGCTaskStore_ConflictDifferentParams1240--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1241=== CONT TestGCTaskStore_DeduplicateSameParams1242--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1243=== CONT TestRedundantMultipartUpload12442026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)12462026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.3ms)12472026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)12482026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.92ms)12492026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (3.1ms)12502026-10-01 09:27:27.210 UTC [700] ERROR: relation "goose_db_version" does not exist at character 3612512026-10-01 09:27:27.210 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12522026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.8ms)12532026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000012542026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.42ms)12552026/10/01 09:27:27 OK 2_object_stats_trigger.sql (2.3ms)12562026/10/01 09:27:27 OK 3_commit_push.sql (1.94ms)12572026/10/01 09:27:27 goose: up to current file version: 31258=== RUN TestPush_RejectsBadRequests/no_roots1259=== PAUSE TestPush_RejectsBadRequests/no_roots1260=== RUN TestPush_RejectsBadRequests/no_objects1261=== PAUSE TestPush_RejectsBadRequests/no_objects1262=== RUN TestPush_RejectsBadRequests/bad_root1263=== PAUSE TestPush_RejectsBadRequests/bad_root1264=== RUN TestPush_RejectsBadRequests/root_not_in_objects1265=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1266=== CONT TestGCTaskStore_StartNew1267--- PASS: TestGCTaskStore_StartNew (0.00s)1268=== CONT TestCommitRacingPendingCleanupKeepsObjects12692026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.75ms)12702026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)12712026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.49ms)12722026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)12732026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.08ms)12742026-10-01 09:27:27.238 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612752026-10-01 09:27:27.238 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12762026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.63ms)12772026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.03ms)12782026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000012792026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.24ms)12802026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.64ms)12812026/10/01 09:27:27 OK 3_commit_push.sql (1.42ms)12822026/10/01 09:27:27 goose: up to current file version: 312832026/10/01 09:27:27 OK 20241026095416_initial_model.sql (10.94ms)1284--- PASS: TestReadRedirectUsesPublicS3URL (0.82s)1285=== CONT TestPush_SignsNarinfosOfItsPendingObjects12862026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (11.45ms)12872026/10/01 09:27:27 OK 20251218171726_add_pins.sql (5.58ms)12882026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)12892026/10/01 09:27:27 OK 20260905000000_add_claims.sql (4.63ms)12902026/10/01 09:27:27 INFO Aborted multipart uploads count=012912026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.89ms)1292--- PASS: TestReadRedirectNar (0.84s)1293=== CONT TestPushWaitsForSweepHoldingRow12942026-10-01 09:27:27.292 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3612952026-10-01 09:27:27.292 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12962026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (13.46ms)12972026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000012982026/10/01 09:27:27 WARN Force mode enabled - objects will be deleted immediately without grace period12992026-10-01 09:27:27.302 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3613002026-10-01 09:27:27.302 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13012026-10-01 09:27:27.310 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3613022026-10-01 09:27:27.310 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13032026/10/01 09:27:27 OK 1_commit_pending_closure.sql (11.01ms)13042026/10/01 09:27:27 OK 2_object_stats_trigger.sql (3.46ms)13052026/10/01 09:27:27 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13062026/10/01 09:27:27 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13072026/10/01 09:27:27 OK 3_commit_push.sql (1.62ms)13082026/10/01 09:27:27 goose: up to current file version: 313092026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.15ms)13102026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)1311--- PASS: TestFailedS3DeleteKeepsTombstone (0.87s)1312=== CONT TestSweepRechecksPendingAfterLocking13132026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.02ms)13142026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.63ms)13152026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)13162026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)13172026/10/01 09:27:27 OK 20251218171726_add_pins.sql (4.17ms)13182026/10/01 09:27:27 OK 20241026095416_initial_model.sql (10.13ms)13192026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.05ms)13202026-10-01 09:27:27.328 UTC [713] ERROR: relation "goose_db_version" does not exist at character 3613212026-10-01 09:27:27.328 UTC [713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13222026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)13232026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)13242026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.86ms)13252026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.04ms)13262026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000013272026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.76ms)13282026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.04ms)13292026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.33ms)1330--- PASS: TestReadRedirectKeepsNarinfoProxied (0.89s)1331=== CONT TestGetExistingObjectsLocksRows13322026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (3.19ms)13332026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.87ms)13342026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.96ms)13352026/10/01 09:27:27 OK 3_commit_push.sql (1.94ms)13362026/10/01 09:27:27 goose: up to current file version: 313372026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.36ms)13382026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000013392026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.32ms)13402026/10/01 09:27:27 OK 1_commit_pending_closure.sql (3.01ms)13412026/10/01 09:27:27 OK 20241026095416_initial_model.sql (10.31ms)13422026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (3.06ms)13432026/10/01 09:27:27 OK 2_object_stats_trigger.sql (2.01ms)13442026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)13452026/10/01 09:27:27 OK 3_commit_push.sql (1.5ms)13462026/10/01 09:27:27 goose: up to current file version: 313472026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.42ms)13482026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000013492026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.77ms)13502026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.65ms)13512026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.86ms)13522026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures13532026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures13542026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures13552026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)13562026/10/01 09:27:27 OK 3_commit_push.sql (1.97ms)13572026/10/01 09:27:27 goose: up to current file version: 313582026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.71ms)13592026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.72ms)13602026-10-01 09:27:27.363 UTC [717] ERROR: relation "goose_db_version" does not exist at character 3613612026-10-01 09:27:27.363 UTC [717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13622026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (9.48ms)13632026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000013642026/10/01 09:27:27 OK 1_commit_pending_closure.sql (3.75ms)13652026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.18ms)13662026/10/01 09:27:27 OK 3_commit_push.sql (1.42ms)13672026/10/01 09:27:27 goose: up to current file version: 313682026/10/01 09:27:27 OK 20241026095416_initial_model.sql (11.25ms)13692026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)1370--- PASS: TestReadProxyRangeRequest (0.94s)1371=== CONT TestClientPushesUseOnePush13722026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.04ms)13732026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)13742026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.65ms)13752026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (3.78ms)13762026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.39ms)13772026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000013782026/10/01 09:27:27 OK 1_commit_pending_closure.sql (3.14ms)13792026/10/01 09:27:27 OK 2_object_stats_trigger.sql (2.53ms)1380--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.96s)1381=== CONT TestRegisterCompletedObjectNeedsPendingRow13822026-10-01 09:27:27.411 UTC [720] ERROR: relation "goose_db_version" does not exist at character 3613832026-10-01 09:27:27.411 UTC [720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13842026/10/01 09:27:27 OK 3_commit_push.sql (1.66ms)13852026/10/01 09:27:27 goose: up to current file version: 313862026-10-01 09:27:27.416 UTC [721] ERROR: relation "goose_db_version" does not exist at character 3613872026-10-01 09:27:27.416 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13882026/10/01 09:27:27 OK 20241026095416_initial_model.sql (8.82ms)13892026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)13902026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.29ms)13912026/10/01 09:27:27 OK 20241026095416_initial_model.sql (10.31ms)13922026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)13932026/10/01 09:27:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13942026/10/01 09:27:27 WARN Refused reserved pin name=worker-x86_64-linux13952026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)13962026/10/01 09:27:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13972026/10/01 09:27:27 INFO Received create pin request method=POST path=/api/pins/my-app13982026/10/01 09:27:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13992026-10-01 09:27:27.437 UTC [724] ERROR: relation "goose_db_version" does not exist at character 3614002026-10-01 09:27:27.437 UTC [724] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1401--- PASS: TestCreatePin_ReservedPins (0.99s)1402=== CONT TestSweepSkipsRowsLockedByPush14032026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.44ms)14042026/10/01 09:27:27 OK 20260905000000_add_claims.sql (4.05ms)14052026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (3.63ms)14062026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (5ms)14072026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.49ms)14082026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000014092026/10/01 09:27:27 OK 20260905000000_add_claims.sql (4.13ms)14102026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.74ms)14112026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.68ms)14122026/10/01 09:27:27 OK 2_object_stats_trigger.sql (2.04ms)14132026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.55ms)14142026/10/01 09:27:27 OK 3_commit_push.sql (1.62ms)14152026/10/01 09:27:27 goose: up to current file version: 314162026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.81ms)14172026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000014182026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)14192026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.62ms)14202026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.56ms)1421--- PASS: TestReadProxyDisabled (1.01s)1422=== CONT TestForceGCDuringPushOffersSweptObject1423=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1424=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1425=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1426=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1427=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection14282026/10/01 09:27:27 OK 2_object_stats_trigger.sql (2.36ms)14292026/10/01 09:27:27 OK 3_commit_push.sql (10.96ms)14302026/10/01 09:27:27 goose: up to current file version: 314312026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (14.73ms)14322026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.33ms)14332026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (3.08ms)14342026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.37ms)14352026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000014362026-10-01 09:27:27.485 UTC [729] ERROR: relation "goose_db_version" does not exist at character 3614372026-10-01 09:27:27.485 UTC [729] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14382026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.96ms)14392026/10/01 09:27:27 OK 2_object_stats_trigger.sql (3.09ms)14402026/10/01 09:27:27 OK 3_commit_push.sql (3.34ms)14412026/10/01 09:27:27 goose: up to current file version: 314422026/10/01 09:27:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14432026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.89ms)14442026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)14452026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.06ms)14462026-10-01 09:27:27.511 UTC [745] ERROR: relation "goose_db_version" does not exist at character 3614472026-10-01 09:27:27.511 UTC [745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)14492026/10/01 09:27:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDVmMzgzMWItMmY2OS00OWVlLWIxNzEtNjdjMTY3M2ZhNmEwLjM4Y2FmMGEzLWE2NjAtNGE5ZC04N2MxLThlMzFmMWZkZTBmOHgxNzkwODQ2ODQ3MDQyNzM0Nzg4 parts=1014502026/10/01 09:27:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14512026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.27ms)1452--- PASS: TestObjectStatsTrigger (0.99s)1453=== CONT TestCacheStatsHandler14542026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.56ms)14552026/10/01 09:27:27 INFO Completed upload id=114562026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures14572026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.63ms)14582026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000014592026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.7ms)14602026/10/01 09:27:27 OK 20241026095416_initial_model.sql (8.76ms)14612026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures14622026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.75ms)14632026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)14642026/10/01 09:27:27 OK 3_commit_push.sql (1.46ms)14652026/10/01 09:27:27 goose: up to current file version: 314662026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.4ms)14672026/10/01 09:27:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14682026/10/01 09:27:27 WARN Found objects in DB but missing from S3, will re-upload count=11469--- PASS: TestService_verifyS3Integrity (1.09s)1470=== CONT TestGCSweepDeliversEachKeyOnce14712026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)14722026-10-01 09:27:27.535 UTC [750] ERROR: relation "goose_db_version" does not exist at character 3614732026-10-01 09:27:27.535 UTC [750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14742026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.19ms)14752026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.65ms)14762026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.65ms)14772026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000014782026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.49ms)14792026/10/01 09:27:27 OK 2_object_stats_trigger.sql (2.4ms)14802026/10/01 09:27:27 OK 20241026095416_initial_model.sql (8.52ms)14812026/10/01 09:27:27 OK 3_commit_push.sql (1.73ms)14822026/10/01 09:27:27 goose: up to current file version: 314832026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)14842026/10/01 09:27:27 OK 20251218171726_add_pins.sql (4.19ms)14852026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)14862026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.63ms)14872026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.48ms)14882026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.9ms)14892026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000014902026-10-01 09:27:27.569 UTC [753] ERROR: relation "goose_db_version" does not exist at character 3614912026-10-01 09:27:27.569 UTC [753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14922026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.29ms)14932026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures14942026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.29ms)14952026/10/01 09:27:27 OK 3_commit_push.sql (1.1ms)14962026/10/01 09:27:27 goose: up to current file version: 314972026/10/01 09:27:27 OK 20241026095416_initial_model.sql (16.59ms)14982026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)14992026/10/01 09:27:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15002026/10/01 09:27:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1501--- PASS: TestService_NativeMTLS (0.65s)1502=== CONT TestPinProtectsFromGC15032026/10/01 09:27:27 OK 20251218171726_add_pins.sql (4.05ms)15042026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)15052026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.77ms)15062026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.49ms)15072026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.12ms)15082026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000015092026-10-01 09:27:27.617 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3615102026-10-01 09:27:27.617 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15112026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.17ms)15122026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.1ms)15132026/10/01 09:27:27 OK 3_commit_push.sql (1.5ms)15142026/10/01 09:27:27 goose: up to current file version: 315152026-10-01 09:27:27.625 UTC [757] ERROR: relation "goose_db_version" does not exist at character 3615162026-10-01 09:27:27.625 UTC [757] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15172026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.42ms)15182026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)15192026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.62ms)15202026/10/01 09:27:27 OK 20241026095416_initial_model.sql (7.38ms)15212026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)15222026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)15232026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.43ms)15242026/10/01 09:27:27 OK 20251218171726_add_pins.sql (1.98ms)15252026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (1.53ms)15262026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)15272026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.96ms)15282026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000015292026/10/01 09:27:27 OK 1_commit_pending_closure.sql (1.75ms)15302026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.67ms)15312026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.32ms)15322026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.15ms)15332026/10/01 09:27:27 OK 3_commit_push.sql (1.54ms)15342026/10/01 09:27:27 goose: up to current file version: 315352026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.98ms)15362026/10/01 09:27:27 goose: successfully migrated database to version: 202609231200001537--- PASS: TestMetricsInventory (0.70s)15382026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.02ms)1539=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15402026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.34ms)15412026/10/01 09:27:27 OK 3_commit_push.sql (902.87µs)15422026/10/01 09:27:27 goose: up to current file version: 315432026/10/01 09:27:27 WARN readiness check failed error="closed pool"1544--- PASS: TestService_readinessHandler (0.61s)1545=== CONT TestClientSharedPathCommittedMidPush15462026-10-01 09:27:27.686 UTC [761] ERROR: relation "goose_db_version" does not exist at character 3615472026-10-01 09:27:27.686 UTC [761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15482026/10/01 09:27:27 OK 20241026095416_initial_model.sql (8.21ms)15492026/10/01 09:27:27 INFO Received cleanup request method=DELETE path=/api/pending_closures15502026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)1551=== NAME TestNARDeduplicationMetadataUploadBug1552 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3423138652/001/store/xb8xfv637s1wafk32q4vn7vyhjcwg6ha-file1.txt15532026/10/01 09:27:27 INFO Aborted multipart uploads count=115542026/10/01 09:27:27 OK 20251218171726_add_pins.sql (4.65ms)1555--- PASS: TestService_healthCheckHandler (0.60s)1556=== CONT TestTombstonedObjectOfferedWithoutWaiting15572026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)1558--- PASS: TestMultipartCleanup (1.13s)1559=== CONT TestCompletedNarNotReofferedAcrossClosures15602026/10/01 09:27:27 OK 20260905000000_add_claims.sql (4.61ms)15612026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.29ms)15622026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.02ms)15632026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000015642026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.71ms)15652026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.43ms)15662026/10/01 09:27:27 OK 3_commit_push.sql (1.41ms)15672026/10/01 09:27:27 goose: up to current file version: 315682026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures15692026-10-01 09:27:27.746 UTC [802] ERROR: relation "goose_db_version" does not exist at character 3615702026-10-01 09:27:27.746 UTC [802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1571--- PASS: TestService_Rustfstest (0.58s)1572=== CONT TestClientWithDependencies15732026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.31ms)15742026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (4.08ms)15752026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.24ms)15762026/10/01 09:27:27 INFO Received push request method=POST path=/api/pushes15772026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)15782026-10-01 09:27:27.788 UTC [823] ERROR: relation "goose_db_version" does not exist at character 3615792026-10-01 09:27:27.788 UTC [823] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15802026/10/01 09:27:27 OK 20260905000000_add_claims.sql (4.42ms)15812026/10/01 09:27:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15822026/10/01 09:27:27 INFO Uploading xb8xfv637s1wafk32q4vn7vyhjcwg6ha-file1.txt (160B)15832026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures15842026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.61ms)15852026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.28ms)15862026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000015872026/10/01 09:27:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15882026/10/01 09:27:27 WARN Failed to register uploaded object key=xb8xfv637s1wafk32q4vn7vyhjcwg6ha.ls error="server returned 404: 404 page not found\n"15892026/10/01 09:27:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15902026/10/01 09:27:27 INFO Signed narinfos id=1 count=115912026/10/01 09:27:27 INFO Uploading 1 narinfos15922026/10/01 09:27:27 OK 1_commit_pending_closure.sql (4.04ms)15932026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.85ms)15942026/10/01 09:27:27 INFO Received complete push request method=POST path=/api/pushes/1/complete15952026/10/01 09:27:27 OK 20241026095416_initial_model.sql (9.07ms)15962026/10/01 09:27:27 WARN Failed to register uploaded object key=xb8xfv637s1wafk32q4vn7vyhjcwg6ha.narinfo error="server returned 404: 404 page not found\n"15972026/10/01 09:27:27 OK 3_commit_push.sql (1.59ms)15982026/10/01 09:27:27 goose: up to current file version: 315992026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)16002026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures16012026/10/01 09:27:27 INFO Upload complete. (62ms)16022026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.71ms)1603=== NAME TestNARDeduplicationMetadataUploadBug1604 metadata_upload_test.go:54: Retrieved narinfo from S3:1605 StorePath: /build/TestNARDeduplicationMetadataUploadBug3423138652/001/store/xb8xfv637s1wafk32q4vn7vyhjcwg6ha-file1.txt1606 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1607 Compression: zstd1608 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1609 NarSize: 1601610 References: 1611 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16122026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.43ms)16132026/10/01 09:27:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1614 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1615 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1616 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16172026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.64ms)16182026-10-01 09:27:27.817 UTC [826] ERROR: relation "goose_db_version" does not exist at character 3616192026-10-01 09:27:27.817 UTC [826] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16202026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (1.44ms)16212026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.8ms)16222026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000016232026-10-01 09:27:27.820 UTC [827] ERROR: relation "goose_db_version" does not exist at character 3616242026-10-01 09:27:27.820 UTC [827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16252026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures16262026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.06ms)16272026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.61ms)16282026/10/01 09:27:27 OK 3_commit_push.sql (1.58ms)16292026/10/01 09:27:27 goose: up to current file version: 316302026/10/01 09:27:27 OK 20241026095416_initial_model.sql (7.93ms)16312026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)16322026/10/01 09:27:27 OK 20241026095416_initial_model.sql (8.82ms)16332026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.16ms)16342026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)16352026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (2.63ms)16362026/10/01 09:27:27 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDVmMzgzMWItMmY2OS00OWVlLWIxNzEtNjdjMTY3M2ZhNmEwLmJmYmM2NTVhLTRiZTktNGExMC05Nzc4LTYwMTkwZTkxNzU3N3gxNzkwODQ2ODQ3MzgwNzg3MDg5 parts=1016372026/10/01 09:27:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16382026/10/01 09:27:27 OK 20251218171726_add_pins.sql (2.57ms)16392026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.08ms)16402026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)16412026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.26ms)16422026/10/01 09:27:27 INFO Completed upload id=116432026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (2.67ms)16442026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000016452026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3ms)16462026/10/01 09:27:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016472026/10/01 09:27:27 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16482026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures16492026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.01ms)16502026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.3ms)16512026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures16522026/10/01 09:27:27 OK 2_object_stats_trigger.sql (925.42µs)16532026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.47ms)16542026/10/01 09:27:27 goose: successfully migrated database to version: 202609231200001655--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.67s)1656=== CONT TestGCSweepSkipsPendingObjects16572026/10/01 09:27:27 OK 3_commit_push.sql (962.28µs)16582026/10/01 09:27:27 goose: up to current file version: 316592026/10/01 09:27:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures16602026/10/01 09:27:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16612026/10/01 09:27:27 OK 1_commit_pending_closure.sql (1.61ms)1662=== NAME TestNARDeduplicationMetadataUploadBug1663 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3423138652/001/store/m24q406jv6i000k9h7m2k00825899h2h-file2.txt16642026/10/01 09:27:27 OK 2_object_stats_trigger.sql (718.7µs)16652026/10/01 09:27:27 OK 3_commit_push.sql (1.23ms)16662026/10/01 09:27:27 goose: up to current file version: 316672026-10-01 09:27:27.861 UTC [848] ERROR: relation "goose_db_version" does not exist at character 3616682026-10-01 09:27:27.861 UTC [848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16692026/10/01 09:27:27 INFO Aborted multipart uploads count=016702026/10/01 09:27:27 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=016712026/10/01 09:27:27 OK 20241026095416_initial_model.sql (8.1ms)16722026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)16732026/10/01 09:27:27 INFO Received push request method=POST path=/api/pushes16742026/10/01 09:27:27 INFO Vacuumed table table=pending_closures16752026/10/01 09:27:27 OK 20251218171726_add_pins.sql (11.57ms)16762026/10/01 09:27:27 INFO Vacuumed table table=pending_objects16772026/10/01 09:27:27 INFO Aborted multipart uploads count=01678=== NAME TestOrphanedObjectsGC1679 orphaned_objects_gc_test.go:290: GC Test Summary:1680 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1681 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1682 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1683 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)16842026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)1685 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1686--- PASS: TestOrphanedObjectsGC (1.37s)1687=== CONT TestClientMultipleUploads16882026/10/01 09:27:27 WARN Force mode enabled - objects will be deleted immediately without grace period16892026/10/01 09:27:27 INFO Vacuumed table table=multipart_uploads16902026/10/01 09:27:27 OK 20260905000000_add_claims.sql (2.93ms)16912026/10/01 09:27:27 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=016922026/10/01 09:27:27 INFO Vacuumed table table=closures16932026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (1.88ms)16942026/10/01 09:27:27 INFO Vacuumed table table=objects16952026/10/01 09:27:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16962026/10/01 09:27:27 INFO Vacuumed table table=pending_closures16972026/10/01 09:27:27 INFO Signed narinfos id=1 count=11698--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.64s)16992026/10/01 09:27:27 OK 20260923120000_add_pushes.sql (1.89ms)1700=== CONT TestLeadElectsOneAndHandsOver17012026/10/01 09:27:27 goose: successfully migrated database to version: 2026092312000017022026/10/01 09:27:27 INFO Vacuumed table table=pending_objects17032026/10/01 09:27:27 INFO Vacuumed table table=multipart_uploads17042026/10/01 09:27:27 INFO Vacuumed table table=closures17052026/10/01 09:27:27 OK 1_commit_pending_closure.sql (2.18ms)17062026/10/01 09:27:27 INFO Vacuumed table table=objects17072026/10/01 09:27:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017082026/10/01 09:27:27 OK 2_object_stats_trigger.sql (1.1ms)1709--- PASS: TestService_createPendingClosureHandler (1.46s)1710=== CONT TestClientIntegration17112026/10/01 09:27:27 OK 3_commit_push.sql (1.5ms)17122026/10/01 09:27:27 goose: up to current file version: 31713--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.69s)1714=== CONT TestClientErrorHandling1715=== RUN TestClientErrorHandling/InvalidStorePath1716=== PAUSE TestClientErrorHandling/InvalidStorePath1717=== RUN TestClientErrorHandling/InvalidAuthToken1718=== PAUSE TestClientErrorHandling/InvalidAuthToken1719=== RUN TestClientErrorHandling/ServerNotAvailable1720=== PAUSE TestClientErrorHandling/ServerNotAvailable1721=== CONT TestResolveDBConnectionString1722=== RUN TestResolveDBConnectionString/flag_wins1723=== PAUSE TestResolveDBConnectionString/flag_wins1724=== RUN TestResolveDBConnectionString/file_when_flag_empty1725=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1726=== RUN TestResolveDBConnectionString/missing_file_is_an_error1727=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1728=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1729=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1730=== RUN TestResolveDBConnectionString/nothing_configured1731=== PAUSE TestResolveDBConnectionString/nothing_configured1732=== CONT TestLeadEndsOnShutdown17332026/10/01 09:27:27 INFO Received uploads request method=POST path=/api/pending_closures17342026/10/01 09:27:27 INFO Received push request method=POST path=/api/pushes17352026/10/01 09:27:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17362026/10/01 09:27:27 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17372026/10/01 09:27:27 INFO Signed narinfos id=2 count=117382026/10/01 09:27:27 WARN Failed to register uploaded object key=m24q406jv6i000k9h7m2k00825899h2h.ls error="server returned 404: 404 page not found\n"17392026/10/01 09:27:27 INFO Uploading 1 narinfos17402026/10/01 09:27:27 INFO Received complete push request method=POST path=/api/pushes/2/complete17412026/10/01 09:27:27 WARN Failed to register uploaded object key=m24q406jv6i000k9h7m2k00825899h2h.narinfo error="server returned 404: 404 page not found\n"17422026/10/01 09:27:27 INFO Upload complete. (51ms)1743=== NAME TestNARDeduplicationMetadataUploadBug1744 metadata_upload_test.go:76: Retrieved narinfo from S3:1745 StorePath: /build/TestNARDeduplicationMetadataUploadBug3423138652/001/store/m24q406jv6i000k9h7m2k00825899h2h-file2.txt1746 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1747 Compression: zstd1748 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1749 NarSize: 1601750 References: 1751 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1752 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1753 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1754 {"version":1,"root":{"type":"regular","size":44}}1755--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)1756=== CONT TestClientCADerivations17572026-10-01 09:27:27.955 UTC [905] ERROR: relation "goose_db_version" does not exist at character 3617582026-10-01 09:27:27.955 UTC [905] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17592026/10/01 09:27:27 INFO Aborted multipart uploads count=017602026/10/01 09:27:27 WARN Force mode enabled - objects will be deleted immediately without grace period17612026/10/01 09:27:27 OK 20241026095416_initial_model.sql (18.44ms)1762--- PASS: TestGetExistingObjectsLocksRows (0.64s)1763=== CONT TestDeduplicatedObjectsRecordedAsPending17642026/10/01 09:27:27 OK 20251210153512_drop_unused_gin_index.sql (5.09ms)17652026/10/01 09:27:27 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=017662026/10/01 09:27:27 OK 20251218171726_add_pins.sql (3.98ms)17672026/10/01 09:27:27 INFO Vacuumed table table=pending_closures17682026/10/01 09:27:27 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)17692026/10/01 09:27:27 INFO Vacuumed table table=pending_objects17702026/10/01 09:27:27 INFO Vacuumed table table=multipart_uploads17712026/10/01 09:27:27 INFO Vacuumed table table=closures17722026/10/01 09:27:27 OK 20260905000000_add_claims.sql (3.27ms)17732026/10/01 09:27:27 INFO Vacuumed table table=objects17742026-10-01 09:27:27.997 UTC [912] ERROR: relation "goose_db_version" does not exist at character 3617752026-10-01 09:27:27.997 UTC [912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17762026/10/01 09:27:27 OK 20260920000000_drop_claims.sql (2.26ms)1777--- PASS: TestSweepRechecksPendingAfterLocking (0.68s)1778=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock17792026-10-01 09:27:28.001 UTC [914] ERROR: relation "goose_db_version" does not exist at character 3617802026-10-01 09:27:28.001 UTC [914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17812026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.49ms)17822026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000017832026/10/01 09:27:28 OK 1_commit_pending_closure.sql (1.89ms)17842026-10-01 09:27:28.004 UTC [915] ERROR: relation "goose_db_version" does not exist at character 3617852026-10-01 09:27:28.004 UTC [915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17862026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.9ms)17872026/10/01 09:27:28 OK 3_commit_push.sql (1.52ms)17882026/10/01 09:27:28 goose: up to current file version: 317892026-10-01 09:27:28.010 UTC [917] ERROR: relation "goose_db_version" does not exist at character 3617902026-10-01 09:27:28.010 UTC [917] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17912026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.92ms)17922026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)17932026/10/01 09:27:28 OK 20241026095416_initial_model.sql (11.48ms)17942026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.77ms)1795--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.61s)17962026/10/01 09:27:28 OK 20251218171726_add_pins.sql (4.24ms)1797=== CONT TestGCMetrics17982026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)17992026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)18002026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.12ms)18012026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.18ms)18022026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.78ms)18032026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.02ms)18042026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)18052026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)18062026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.8ms)18072026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)18082026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.32ms)18092026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.53ms)18102026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (3.3ms)18112026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.48ms)18122026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.49ms)18132026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)18142026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.27ms)18152026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000018162026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.75ms)18172026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.26ms)18182026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000018192026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.81ms)18202026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.19ms)18212026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000018222026/10/01 09:27:28 OK 20260905000000_add_claims.sql (4.4ms)18232026/10/01 09:27:28 OK 1_commit_pending_closure.sql (3.25ms)18242026/10/01 09:27:28 OK 2_object_stats_trigger.sql (2.17ms)18252026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.64ms)18262026/10/01 09:27:28 OK 2_object_stats_trigger.sql (2.11ms)18272026/10/01 09:27:28 OK 3_commit_push.sql (1.96ms)18282026/10/01 09:27:28 goose: up to current file version: 318292026/10/01 09:27:28 OK 1_commit_pending_closure.sql (3.16ms)18302026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.45ms)18312026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.03ms)18322026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000018332026/10/01 09:27:28 OK 3_commit_push.sql (1.63ms)18342026/10/01 09:27:28 goose: up to current file version: 318352026/10/01 09:27:28 OK 3_commit_push.sql (1.5ms)18362026/10/01 09:27:28 goose: up to current file version: 318372026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.33ms)18382026/10/01 09:27:28 OK 2_object_stats_trigger.sql (2.29ms)18392026/10/01 09:27:28 OK 3_commit_push.sql (1.54ms)18402026/10/01 09:27:28 goose: up to current file version: 318412026-10-01 09:27:28.053 UTC [938] ERROR: relation "goose_db_version" does not exist at character 3618422026-10-01 09:27:28.053 UTC [938] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18432026-10-01 09:27:28.079 UTC [955] ERROR: relation "goose_db_version" does not exist at character 3618442026-10-01 09:27:28.079 UTC [955] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18452026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.18ms)18462026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures18472026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)18482026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.07ms)18492026/10/01 09:27:28 INFO Aborted multipart uploads count=018502026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)18512026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period18522026/10/01 09:27:28 OK 20241026095416_initial_model.sql (8.38ms)18532026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.7ms)18542026/10/01 09:27:28 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=018552026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)18562026/10/01 09:27:28 INFO Vacuumed table table=pending_closures18572026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (1.71ms)18582026/10/01 09:27:28 INFO Vacuumed table table=pending_objects18592026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads18602026/10/01 09:27:28 INFO Vacuumed table table=closures18612026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.18ms)18622026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.78ms)18632026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000018642026/10/01 09:27:28 INFO Vacuumed table table=objects18652026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.66ms)18662026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.71ms)18672026/10/01 09:27:28 OK 2_object_stats_trigger.sql (2.04ms)18682026/10/01 09:27:28 INFO Aborted multipart uploads count=018692026/10/01 09:27:28 OK 3_commit_push.sql (1.41ms)18702026/10/01 09:27:28 goose: up to current file version: 318712026/10/01 09:27:28 OK 20260905000000_add_claims.sql (4.64ms)18722026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period18732026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.42ms)18742026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.73ms)18752026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000018762026-10-01 09:27:28.111 UTC [975] ERROR: relation "goose_db_version" does not exist at character 3618772026-10-01 09:27:28.111 UTC [975] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18782026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.39ms)18792026/10/01 09:27:28 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=018802026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.64ms)18812026/10/01 09:27:28 INFO Vacuumed table table=pending_closures18822026/10/01 09:27:28 INFO Vacuumed table table=pending_objects18832026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads18842026/10/01 09:27:28 INFO Vacuumed table table=closures18852026/10/01 09:27:28 OK 3_commit_push.sql (1.11ms)18862026/10/01 09:27:28 goose: up to current file version: 318872026/10/01 09:27:28 INFO Vacuumed table table=objects1888--- PASS: TestSweepSkipsRowsLockedByPush (0.68s)1889=== CONT TestClientFallsBackToClosures1890--- PASS: TestCacheStatsHandler (0.60s)1891=== CONT TestPushDedupSurvivesConcurrentGC18922026/10/01 09:27:28 OK 20241026095416_initial_model.sql (8.77ms)18932026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)18942026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.68ms)18952026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)18962026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.35ms)18972026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (1.91ms)18982026-10-01 09:27:28.140 UTC [981] ERROR: relation "goose_db_version" does not exist at character 3618992026-10-01 09:27:28.140 UTC [981] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19002026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.4ms)19012026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000019022026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.25ms)19032026/10/01 09:27:28 OK 2_object_stats_trigger.sql (773.37µs)19042026/10/01 09:27:28 OK 3_commit_push.sql (1.15ms)19052026/10/01 09:27:28 goose: up to current file version: 319062026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.68ms)19072026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)19082026/10/01 09:27:28 INFO Aborted multipart uploads count=019092026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.59ms)19102026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period19112026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)19122026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.84ms)19132026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (1.6ms)19142026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.94ms)19152026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000019162026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.2ms)19172026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.48ms)19182026/10/01 09:27:28 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=019192026/10/01 09:27:28 OK 3_commit_push.sql (1.46ms)19202026/10/01 09:27:28 goose: up to current file version: 319212026/10/01 09:27:28 INFO Vacuumed table table=pending_closures19222026/10/01 09:27:28 INFO Vacuumed table table=pending_objects19232026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads19242026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures19252026/10/01 09:27:28 INFO Vacuumed table table=closures19262026/10/01 09:27:28 INFO Vacuumed table table=objects1927--- PASS: TestGCSweepDeliversEachKeyOnce (0.65s)1928=== CONT TestGCBugBareHashReferences19292026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes19302026/10/01 09:27:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19312026/10/01 09:27:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19322026/10/01 09:27:28 INFO Uploading qd8dlnsm0xgj2jl5nr6ngx9lnis9l7b4-b (208B)19332026/10/01 09:27:28 INFO Uploading q869hl8az23z3zpv94pn5bmsr3j0lmgb-shared-dep (136B)19342026/10/01 09:27:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDVmMzgzMWItMmY2OS00OWVlLWIxNzEtNjdjMTY3M2ZhNmEwLjhmOTg1OWY3LTZjY2YtNDkxYS05YWVkLTBiNzRkYWExZmMwMngxNzkwODQ2ODQ4MTg3Njg2MjA219352026/10/01 09:27:28 WARN Failed to register uploaded object key=lig3ldp9mziq0v8p0ba9dsljr35n7bj0.ls error="server returned 404: 404 page not found\n"19362026-10-01 09:27:28.221 UTC [1041] ERROR: relation "goose_db_version" does not exist at character 3619372026-10-01 09:27:28.221 UTC [1041] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19382026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19392026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/1vpv0smzvi4gsn9xglaiw3grrfqic7qv0xswjw74k7k96rfjjfga.nar.zst error="server returned 404: 404 page not found\n"19402026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19412026/10/01 09:27:28 WARN Failed to register uploaded object key=qd8dlnsm0xgj2jl5nr6ngx9lnis9l7b4.ls error="server returned 404: 404 page not found\n"19422026/10/01 09:27:28 WARN Failed to register uploaded object key=q869hl8az23z3zpv94pn5bmsr3j0lmgb.ls error="server returned 404: 404 page not found\n"19432026/10/01 09:27:28 INFO Signed narinfos id=1 count=319442026-10-01 09:27:28.223 UTC [1040] ERROR: relation "goose_db_version" does not exist at character 3619452026-10-01 09:27:28.223 UTC [1040] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19462026/10/01 09:27:28 INFO Uploading 3 narinfos19472026/10/01 09:27:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDVmMzgzMWItMmY2OS00OWVlLWIxNzEtNjdjMTY3M2ZhNmEwLjhmOTg1OWY3LTZjY2YtNDkxYS05YWVkLTBiNzRkYWExZmMwMngxNzkwODQ2ODQ4MTg3Njg2MjA2 parts=11948--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.57s)1949=== CONT TestReadProxyNarinfoAlreadyDecompressed19502026/10/01 09:27:28 WARN Failed to register uploaded object key=lig3ldp9mziq0v8p0ba9dsljr35n7bj0.narinfo error="server returned 404: 404 page not found\n"19512026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete19522026/10/01 09:27:28 WARN Failed to register uploaded object key=qd8dlnsm0xgj2jl5nr6ngx9lnis9l7b4.narinfo error="server returned 404: 404 page not found\n"19532026/10/01 09:27:28 WARN Failed to register uploaded object key=q869hl8az23z3zpv94pn5bmsr3j0lmgb.narinfo error="server returned 404: 404 page not found\n"19542026/10/01 09:27:28 OK 20241026095416_initial_model.sql (7.82ms)1955=== NAME TestPinProtectsFromGC19562026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)1957 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC782992138/001/store/kf2cg3ki9nmdxw64dbnqijqv3k9lhgnx-pinned-file.txt1958 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC782992138/001/store/gh82cg5fm68g6vrq2lf0dz2gf4ckh66z-unpinned-file.txt19592026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.76ms)19602026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures19612026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.82ms)19622026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)19632026/10/01 09:27:28 INFO Upload complete. (88ms)1964=== NAME TestClientPushesUseOnePush1965 client_pushes_test.go:97: Retrieved narinfo from S3:1966 StorePath: /build/TestClientPushesUseOnePush868490565/001/store/q869hl8az23z3zpv94pn5bmsr3j0lmgb-shared-dep1967 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1968 Compression: zstd1969 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821970 NarSize: 1361971 References: 1972 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19732026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)19742026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.29ms)1975 client_pushes_test.go:97: Retrieved narinfo from S3:1976 StorePath: /build/TestClientPushesUseOnePush868490565/001/store/lig3ldp9mziq0v8p0ba9dsljr35n7bj0-a1977 URL: nar/1vpv0smzvi4gsn9xglaiw3grrfqic7qv0xswjw74k7k96rfjjfga.nar.zst1978 Compression: zstd1979 NarHash: sha256:1vpv0smzvi4gsn9xglaiw3grrfqic7qv0xswjw74k7k96rfjjfga1980 NarSize: 2081981 References: /build/TestClientPushesUseOnePush868490565/001/store/q869hl8az23z3zpv94pn5bmsr3j0lmgb-shared-dep1982 CA: text:sha256:02qa18nfrs0abyimscly97mx0nhmhg1pvwpmm2klkpnrqi52fr0r19832026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.88ms)19842026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)1985 client_pushes_test.go:97: Retrieved narinfo from S3:1986 StorePath: /build/TestClientPushesUseOnePush868490565/001/store/qd8dlnsm0xgj2jl5nr6ngx9lnis9l7b4-b1987 URL: nar/1vpv0smzvi4gsn9xglaiw3grrfqic7qv0xswjw74k7k96rfjjfga.nar.zst1988 Compression: zstd1989 NarHash: sha256:1vpv0smzvi4gsn9xglaiw3grrfqic7qv0xswjw74k7k96rfjjfga1990 NarSize: 2081991 References: /build/TestClientPushesUseOnePush868490565/001/store/q869hl8az23z3zpv94pn5bmsr3j0lmgb-shared-dep1992 CA: text:sha256:02qa18nfrs0abyimscly97mx0nhmhg1pvwpmm2klkpnrqi52fr0r1993--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.54s)1994=== CONT TestService_AuthMiddleware_OIDC19952026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (3.2ms)19962026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.08ms)19972026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000019982026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.99ms)1999--- PASS: TestClientPushesUseOnePush (0.86s)2000=== CONT TestReadProxyInvalidPath20012026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.35ms)20022026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.79ms)20032026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.45ms)20042026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.65ms)20052026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000020062026/10/01 09:27:28 OK 3_commit_push.sql (2.05ms)20072026/10/01 09:27:28 goose: up to current file version: 320082026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.19ms)20092026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.51ms)20102026/10/01 09:27:28 OK 3_commit_push.sql (1.01ms)20112026/10/01 09:27:28 goose: up to current file version: 320122026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures20132026-10-01 09:27:28.273 UTC [1097] ERROR: relation "goose_db_version" does not exist at character 3620142026-10-01 09:27:28.273 UTC [1097] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20152026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.08ms)20162026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)20172026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.94ms)2018--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.84s)2019=== CONT TestReadProxy40420202026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)20212026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.13ms)20222026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.26ms)20232026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.74ms)20242026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000020252026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.09ms)20262026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.53ms)20272026/10/01 09:27:28 OK 3_commit_push.sql (2.27ms)20282026/10/01 09:27:28 goose: up to current file version: 320292026/10/01 09:27:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42839/oidc20302026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes20312026/10/01 09:27:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20322026/10/01 09:27:28 INFO Uploading kf2cg3ki9nmdxw64dbnqijqv3k9lhgnx-pinned-file.txt (128B)20332026/10/01 09:27:28 WARN Failed to register uploaded object key=kf2cg3ki9nmdxw64dbnqijqv3k9lhgnx.ls error="server returned 404: 404 page not found\n"20342026-10-01 09:27:28.326 UTC [1155] ERROR: relation "goose_db_version" does not exist at character 3620352026-10-01 09:27:28.326 UTC [1155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20362026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20372026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20382026/10/01 09:27:28 INFO Signed narinfos id=1 count=120392026/10/01 09:27:28 INFO Uploading 1 narinfos20402026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures20412026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete20422026/10/01 09:27:28 WARN Failed to register uploaded object key=kf2cg3ki9nmdxw64dbnqijqv3k9lhgnx.narinfo error="server returned 404: 404 page not found\n"20432026/10/01 09:27:28 INFO Upload complete. (81ms)20442026/10/01 09:27:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20452026-10-01 09:27:28.360 UTC [1175] ERROR: relation "goose_db_version" does not exist at character 3620462026-10-01 09:27:28.360 UTC [1175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20472026/10/01 09:27:28 INFO Aborted multipart uploads count=020482026/10/01 09:27:28 OK 20241026095416_initial_model.sql (18.91ms)20492026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period20502026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (3.68ms)20512026/10/01 09:27:28 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=020522026/10/01 09:27:28 OK 20241026095416_initial_model.sql (12.29ms)20532026/10/01 09:27:28 OK 20251218171726_add_pins.sql (9.48ms)20542026/10/01 09:27:28 INFO Vacuumed table table=pending_closures20552026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (11.49ms)20562026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes20572026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (14.86ms)2058=== NAME TestClientWithDependencies20592026/10/01 09:27:28 INFO Vacuumed table table=pending_objects2060 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3844995857/001/store/czlb9zbfh0qf7mhjvw7inl7w2v0g9k6g-test-script20612026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads20622026/10/01 09:27:28 INFO Vacuumed table table=closures20632026/10/01 09:27:28 OK 20251218171726_add_pins.sql (16.1ms)20642026-10-01 09:27:28.408 UTC [1248] ERROR: relation "goose_db_version" does not exist at character 3620652026-10-01 09:27:28.408 UTC [1248] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20662026/10/01 09:27:28 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20672026/10/01 09:27:28 INFO Uploading fq9vr6fnj4bhrf4m8cac44daz76zwg77-shared-dep (136B)20682026/10/01 09:27:28 INFO Uploading pa1xbqxff7mn8lm06az9d9yl3n312rvd-top (224B)20692026/10/01 09:27:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDVmMzgzMWItMmY2OS00OWVlLWIxNzEtNjdjMTY3M2ZhNmEwLmIxMGJlN2E0LTQzZTktNDg5Zi04YjNiLTUxNGM4MTM5Yzg3ZngxNzkwODQ2ODQ3ODA0MDQ3NTY0 parts=1220702026/10/01 09:27:28 OK 20260905000000_add_claims.sql (15.33ms)20712026/10/01 09:27:28 INFO Vacuumed table table=objects20722026/10/01 09:27:28 WARN Failed to register uploaded object key=fq9vr6fnj4bhrf4m8cac44daz76zwg77.ls error="server returned 404: 404 page not found\n"20732026/10/01 09:27:28 WARN Failed to register uploaded object key=pa1xbqxff7mn8lm06az9d9yl3n312rvd.ls error="server returned 404: 404 page not found\n"20742026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/11qz50q9sn07mbhl72bq8raf2zwdn02gf9f976y4yngniiw1p62y.nar.zst error="server returned 404: 404 page not found\n"2075--- PASS: TestRedundantMultipartUpload (1.22s)20762026/10/01 09:27:28 INFO lead: acquired remote=192.0.2.1:12342077=== CONT TestReadProxyHead20782026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20792026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20802026/10/01 09:27:28 INFO Signed narinfos id=1 count=220812026/10/01 09:27:28 INFO Uploading 2 narinfos20822026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (9.3ms)20832026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (5.76ms)2084--- PASS: TestPushWaitsForSweepHoldingRow (1.13s)2085=== CONT TestReadProxyNarStreaming20862026/10/01 09:27:28 WARN Failed to register uploaded object key=fq9vr6fnj4bhrf4m8cac44daz76zwg77.narinfo error="server returned 404: 404 page not found\n"20872026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete20882026/10/01 09:27:28 WARN Failed to register uploaded object key=pa1xbqxff7mn8lm06az9d9yl3n312rvd.narinfo error="server returned 404: 404 page not found\n"20892026/10/01 09:27:28 OK 20260905000000_add_claims.sql (5.11ms)20902026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.3ms)20912026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000020922026-10-01 09:27:28.424 UTC [1251] ERROR: relation "goose_db_version" does not exist at character 3620932026-10-01 09:27:28.424 UTC [1251] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2094--- PASS: TestGCSweepSkipsPendingObjects (0.57s)2095=== CONT TestCacheConfigHandler2096=== RUN TestCacheConfigHandler/full_config,_no_issuer20972026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.71ms)2098=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2099=== RUN TestCacheConfigHandler/no_cache_url_configured2100=== PAUSE TestCacheConfigHandler/no_cache_url_configured2101=== RUN TestCacheConfigHandler/no_signing_keys2102=== PAUSE TestCacheConfigHandler/no_signing_keys2103=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2104=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2105=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21062026/10/01 09:27:28 OK 20241026095416_initial_model.sql (8.18ms)21072026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.38ms)21082026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.89ms)21092026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000021102026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)21112026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.19ms)2112=== NAME TestClientMultipleUploads2113 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads207723215/001/store/ahiwn9f6iqvd3iqkck1n1vzciajra6gj-test-file-0.txt21142026/10/01 09:27:28 OK 3_commit_push.sql (1.58ms)21152026/10/01 09:27:28 goose: up to current file version: 321162026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.73ms)21172026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.65ms)21182026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes21192026/10/01 09:27:28 OK 2_object_stats_trigger.sql (962.39µs)21202026/10/01 09:27:28 INFO Upload complete. (110ms)21212026/10/01 09:27:28 OK 3_commit_push.sql (807.74µs)21222026/10/01 09:27:28 goose: up to current file version: 321232026/10/01 09:27:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21242026/10/01 09:27:28 INFO Uploading gh82cg5fm68g6vrq2lf0dz2gf4ckh66z-unpinned-file.txt (128B)2125=== NAME TestClientSharedPathCommittedMidPush2126 client_integration_test.go:680: Retrieved narinfo from S3:2127 StorePath: /build/TestClientSharedPathCommittedMidPush783362750/001/store/fq9vr6fnj4bhrf4m8cac44daz76zwg77-shared-dep2128 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2129 Compression: zstd2130 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822131 NarSize: 1362132 References: 2133 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21342026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)2135 client_integration_test.go:680: Retrieved narinfo from S3:2136 StorePath: /build/TestClientSharedPathCommittedMidPush783362750/001/store/pa1xbqxff7mn8lm06az9d9yl3n312rvd-top2137 URL: nar/11qz50q9sn07mbhl72bq8raf2zwdn02gf9f976y4yngniiw1p62y.nar.zst2138 Compression: zstd2139 NarHash: sha256:11qz50q9sn07mbhl72bq8raf2zwdn02gf9f976y4yngniiw1p62y2140 NarSize: 2242141 References: /build/TestClientSharedPathCommittedMidPush783362750/001/store/fq9vr6fnj4bhrf4m8cac44daz76zwg77-shared-dep2142 CA: text:sha256:0a8pr4liz4f5z8jbc1rzvyl32davh55xfyzrdh0858pvq0m7qfxj2143=== NAME TestClientWithDependencies2144 client_integration_test.go:615: Found 1 dependencies (including self)21452026/10/01 09:27:28 WARN Failed to register uploaded object key=gh82cg5fm68g6vrq2lf0dz2gf4ckh66z.ls error="server returned 404: 404 page not found\n"21462026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21472026/10/01 09:27:28 INFO Signed narinfos id=2 count=121482026/10/01 09:27:28 OK 20241026095416_initial_model.sql (8.87ms)21492026/10/01 09:27:28 INFO Uploading 1 narinfos21502026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21512026/10/01 09:27:28 OK 20260905000000_add_claims.sql (4.4ms)21522026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)21532026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.15ms)21542026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/2/complete21552026/10/01 09:27:28 WARN Failed to register uploaded object key=gh82cg5fm68g6vrq2lf0dz2gf4ckh66z.narinfo error="server returned 404: 404 page not found\n"21562026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.1ms)21572026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.97ms)21582026/10/01 09:27:28 goose: successfully migrated database to version: 202609231200002159--- PASS: TestClientSharedPathCommittedMidPush (0.76s)2160=== CONT TestService_ReadScope_PublicByDefault21612026/10/01 09:27:28 INFO Upload complete. (57ms)21622026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)21632026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.73ms)21642026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.58ms)21652026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.69ms)21662026/10/01 09:27:28 OK 3_commit_push.sql (1.88ms)21672026/10/01 09:27:28 goose: up to current file version: 321682026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.37ms)21692026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.83ms)21702026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000021712026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.89ms)21722026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.56ms)21732026/10/01 09:27:28 OK 3_commit_push.sql (1.56ms)21742026/10/01 09:27:28 goose: up to current file version: 32175=== NAME TestClientMultipleUploads2176 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads207723215/001/store/f94d1pvdakbfzql53igs1axy2zs1v3kg-test-file-1.txt21772026/10/01 09:27:28 INFO lead: acquired remote=192.0.2.1:123421782026/10/01 09:27:28 INFO lead: released remote=192.0.2.1:12342179--- PASS: TestLeadEndsOnShutdown (0.56s)2180=== CONT TestService_ReadAuthMiddleware21812026/10/01 09:27:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures2182=== NAME TestClientIntegration2183 client_integration_test.go:286: Created store path: /build/TestClientIntegration1118162857/002/store/mr0fx18i8jra60g6fw3iynhakqy50xw7-test-file.txt21842026/10/01 09:27:28 INFO Garbage collection started21852026/10/01 09:27:28 INFO Aborted multipart uploads count=02186=== NAME TestClientMultipleUploads2187 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads207723215/001/store/7xmgvvqal86sixb3ngzr0ph3dsrn6g6d-test-file-2.txt21882026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period21892026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes21902026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures21912026/10/01 09:27:28 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=021922026/10/01 09:27:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21932026/10/01 09:27:28 INFO Uploading czlb9zbfh0qf7mhjvw7inl7w2v0g9k6g-test-script (136B)21942026-10-01 09:27:28.524 UTC [1425] ERROR: relation "goose_db_version" does not exist at character 3621952026-10-01 09:27:28.524 UTC [1425] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21962026/10/01 09:27:28 INFO Vacuumed table table=pending_closures21972026-10-01 09:27:28.525 UTC [1438] ERROR: relation "goose_db_version" does not exist at character 3621982026-10-01 09:27:28.525 UTC [1438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21992026/10/01 09:27:28 WARN Failed to register uploaded object key=czlb9zbfh0qf7mhjvw7inl7w2v0g9k6g.ls error="server returned 404: 404 page not found\n"22002026/10/01 09:27:28 INFO Vacuumed table table=pending_objects22012026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"22022026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads22032026/10/01 09:27:28 WARN Failed to register uploaded object key=log/8kld5dp83mlh2d7spif8p930z0326xpq-test-script.drv error="server returned 404: 404 page not found\n"22042026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22052026/10/01 09:27:28 INFO Signed narinfos id=1 count=122062026/10/01 09:27:28 INFO Uploading 1 narinfos22072026/10/01 09:27:28 INFO Vacuumed table table=closures2208--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.55s)2209=== CONT TestService_RequireScope_OIDC22102026/10/01 09:27:28 INFO Vacuumed table table=objects22112026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete22122026/10/01 09:27:28 WARN Failed to register uploaded object key=czlb9zbfh0qf7mhjvw7inl7w2v0g9k6g.narinfo error="server returned 404: 404 page not found\n"22132026/10/01 09:27:28 INFO Upload complete. (66ms)22142026-10-01 09:27:28.539 UTC [1457] ERROR: relation "goose_db_version" does not exist at character 3622152026-10-01 09:27:28.539 UTC [1457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22162026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.06ms)22172026/10/01 09:27:28 OK 20241026095416_initial_model.sql (10.78ms)2218=== NAME TestClientWithDependencies2219 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3844995857/001/store) requires matching store prefix22202026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)22212026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)22222026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.82ms)22232026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.1ms)2224--- PASS: TestClientWithDependencies (0.78s)2225=== CONT TestService_AuthMiddleware_MTLSProxyHeader22262026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)22272026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)22282026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.97ms)22292026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.57ms)22302026/10/01 09:27:28 OK 20241026095416_initial_model.sql (9.56ms)22312026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (3.14ms)22322026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)22332026-10-01 09:27:28.557 UTC [1461] ERROR: relation "goose_db_version" does not exist at character 3622342026-10-01 09:27:28.557 UTC [1461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22352026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (6.77ms)22362026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.22ms)22372026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (4.18ms)22382026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000022392026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.44ms)22402026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000022412026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)22422026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.9ms)22432026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.38ms)22442026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.71ms)22452026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.3ms)22462026/10/01 09:27:28 INFO lead: released remote=192.0.2.1:123422472026/10/01 09:27:28 OK 2_object_stats_trigger.sql (981.8µs)22482026/10/01 09:27:28 OK 3_commit_push.sql (928.04µs)22492026/10/01 09:27:28 goose: up to current file version: 322502026/10/01 09:27:28 OK 3_commit_push.sql (1.01ms)22512026/10/01 09:27:28 goose: up to current file version: 322522026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.17ms)22532026/10/01 09:27:28 OK 20241026095416_initial_model.sql (8.02ms)22542026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes22552026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.62ms)22562026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000022572026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)22582026-10-01 09:27:28.574 UTC [1496] ERROR: relation "goose_db_version" does not exist at character 3622592026-10-01 09:27:28.574 UTC [1496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22602026/10/01 09:27:28 OK 1_commit_pending_closure.sql (3.06ms)22612026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.02ms)22622026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.14ms)22632026/10/01 09:27:28 OK 3_commit_push.sql (672.73µs)22642026/10/01 09:27:28 goose: up to current file version: 322652026/10/01 09:27:28 INFO Aborted multipart uploads count=022662026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)22672026/10/01 09:27:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22682026/10/01 09:27:28 INFO Uploading mr0fx18i8jra60g6fw3iynhakqy50xw7-test-file.txt (152B)22692026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period2270=== NAME TestClientCADerivations2271 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations867817050/001/store/6z0bq2j8g6z91n913wq6k4k452sqwcja-ca-test22722026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.41ms)22732026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"22742026/10/01 09:27:28 WARN Failed to register uploaded object key=mr0fx18i8jra60g6fw3iynhakqy50xw7.ls error="server returned 404: 404 page not found\n"22752026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22762026/10/01 09:27:28 INFO Signed narinfos id=1 count=122772026/10/01 09:27:28 INFO Uploading 1 narinfos22782026/10/01 09:27:28 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=022792026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.18ms)22802026/10/01 09:27:28 INFO Vacuumed table table=pending_closures22812026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes22822026/10/01 09:27:28 INFO Vacuumed table table=pending_objects22832026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads22842026/10/01 09:27:28 INFO Vacuumed table table=closures22852026/10/01 09:27:28 INFO Vacuumed table table=objects22862026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete22872026/10/01 09:27:28 WARN Failed to register uploaded object key=mr0fx18i8jra60g6fw3iynhakqy50xw7.narinfo error="server returned 404: 404 page not found\n"22882026/10/01 09:27:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39335/oidc2289--- PASS: TestGCMetrics (0.57s)2290=== CONT TestIsValidCachePath2291=== RUN TestIsValidCachePath/narinfo2292=== PAUSE TestIsValidCachePath/narinfo2293=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2294=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2295=== RUN TestIsValidCachePath/nar_zst2296=== PAUSE TestIsValidCachePath/nar_zst2297=== RUN TestIsValidCachePath/nar_xz2298=== PAUSE TestIsValidCachePath/nar_xz2299=== RUN TestIsValidCachePath/nar_bz22300=== PAUSE TestIsValidCachePath/nar_bz22301=== RUN TestIsValidCachePath/nar_uncompressed2302=== PAUSE TestIsValidCachePath/nar_uncompressed2303=== RUN TestIsValidCachePath/ls2304=== PAUSE TestIsValidCachePath/ls2305=== RUN TestIsValidCachePath/log2306=== PAUSE TestIsValidCachePath/log2307=== RUN TestIsValidCachePath/realisation2308=== PAUSE TestIsValidCachePath/realisation2309=== RUN TestIsValidCachePath/nix-cache-info2310=== PAUSE TestIsValidCachePath/nix-cache-info2311=== RUN TestIsValidCachePath/index.html2312=== PAUSE TestIsValidCachePath/index.html2313=== RUN TestIsValidCachePath/traversal_parent2314=== PAUSE TestIsValidCachePath/traversal_parent2315=== RUN TestIsValidCachePath/traversal_in_middle2316=== PAUSE TestIsValidCachePath/traversal_in_middle2317=== RUN TestIsValidCachePath/invalid_char_e2318=== PAUSE TestIsValidCachePath/invalid_char_e2319=== RUN TestIsValidCachePath/invalid_char_u2320=== PAUSE TestIsValidCachePath/invalid_char_u2321=== RUN TestIsValidCachePath/random_path2322=== PAUSE TestIsValidCachePath/random_path2323=== RUN TestIsValidCachePath/empty2324=== PAUSE TestIsValidCachePath/empty2325=== RUN TestIsValidCachePath/leading_slash2326=== PAUSE TestIsValidCachePath/leading_slash2327=== RUN TestIsValidCachePath/wrong_extension2328=== PAUSE TestIsValidCachePath/wrong_extension2329=== RUN TestIsValidCachePath/short_hash2330=== PAUSE TestIsValidCachePath/short_hash2331=== CONT TestProxyHeadersOnlyTrustedOnSocket23322026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (16.64ms)23332026/10/01 09:27:28 OK 20241026095416_initial_model.sql (19.33ms)23342026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000023352026/10/01 09:27:28 INFO Upload complete. (75ms)23362026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)23372026/10/01 09:27:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)23382026/10/01 09:27:28 INFO Uploading ahiwn9f6iqvd3iqkck1n1vzciajra6gj-test-file-0.txt (160B)23392026/10/01 09:27:28 INFO Uploading f94d1pvdakbfzql53igs1axy2zs1v3kg-test-file-1.txt (160B)23402026/10/01 09:27:28 INFO Uploading 7xmgvvqal86sixb3ngzr0ph3dsrn6g6d-test-file-2.txt (160B)23412026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.31ms)23422026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.91ms)23432026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.47ms)23442026/10/01 09:27:28 OK 3_commit_push.sql (1.11ms)23452026/10/01 09:27:28 goose: up to current file version: 323462026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"23472026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"23482026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"23492026/10/01 09:27:28 WARN Failed to register uploaded object key=ahiwn9f6iqvd3iqkck1n1vzciajra6gj.ls error="server returned 404: 404 page not found\n"23502026/10/01 09:27:28 WARN Failed to register uploaded object key=7xmgvvqal86sixb3ngzr0ph3dsrn6g6d.ls error="server returned 404: 404 page not found\n"23512026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23522026/10/01 09:27:28 WARN Failed to register uploaded object key=f94d1pvdakbfzql53igs1axy2zs1v3kg.ls error="server returned 404: 404 page not found\n"23532026/10/01 09:27:28 INFO Signed narinfos id=1 count=323542026/10/01 09:27:28 INFO Uploading 3 narinfos2355=== NAME TestClientCADerivations2356 client_ca_test.go:139: Found 1 dependencies (including self)23572026/10/01 09:27:28 WARN Failed to register uploaded object key=ahiwn9f6iqvd3iqkck1n1vzciajra6gj.narinfo error="server returned 404: 404 page not found\n"23582026/10/01 09:27:28 WARN Failed to register uploaded object key=7xmgvvqal86sixb3ngzr0ph3dsrn6g6d.narinfo error="server returned 404: 404 page not found\n"23592026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete23602026/10/01 09:27:28 WARN Failed to register uploaded object key=f94d1pvdakbfzql53igs1axy2zs1v3kg.narinfo error="server returned 404: 404 page not found\n"23612026/10/01 09:27:28 INFO lead: acquired remote=192.0.2.1:123423622026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)23632026/10/01 09:27:28 OK 20260905000000_add_claims.sql (4.35ms)23642026/10/01 09:27:28 INFO lead: released remote=192.0.2.1:12342365--- PASS: TestLeadElectsOneAndHandsOver (0.72s)2366=== CONT TestReadProxyNarinfo23672026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.55ms)23682026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.59ms)23692026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000023702026/10/01 09:27:28 INFO Upload complete. (93ms)2371=== NAME TestClientMultipleUploads2372 client_integration_test.go:369: Uploaded 3 paths in 125.099516ms23732026/10/01 09:27:28 OK 1_commit_pending_closure.sql (3.4ms)23742026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.74ms)23752026/10/01 09:27:28 OK 3_commit_push.sql (1.07ms)23762026/10/01 09:27:28 goose: up to current file version: 32377--- PASS: TestClientMultipleUploads (0.75s)2378=== CONT TestParseSingleRange2379=== RUN TestParseSingleRange/none2380=== PAUSE TestParseSingleRange/none2381=== RUN TestParseSingleRange/unknown_unit2382=== PAUSE TestParseSingleRange/unknown_unit2383=== RUN TestParseSingleRange/multi-range_ignored2384=== PAUSE TestParseSingleRange/multi-range_ignored2385=== RUN TestParseSingleRange/malformed_no_dash2386=== PAUSE TestParseSingleRange/malformed_no_dash2387=== RUN TestParseSingleRange/malformed_both_empty2388=== PAUSE TestParseSingleRange/malformed_both_empty2389=== RUN TestParseSingleRange/malformed_end_before_start2390=== PAUSE TestParseSingleRange/malformed_end_before_start2391=== RUN TestParseSingleRange/closed2392=== PAUSE TestParseSingleRange/closed2393=== RUN TestParseSingleRange/open-ended2394=== PAUSE TestParseSingleRange/open-ended2395=== RUN TestParseSingleRange/end_clamped_to_size2396=== PAUSE TestParseSingleRange/end_clamped_to_size2397=== RUN TestParseSingleRange/suffix2398=== PAUSE TestParseSingleRange/suffix2399=== RUN TestParseSingleRange/suffix_exceeds_size2400=== PAUSE TestParseSingleRange/suffix_exceeds_size2401=== RUN TestParseSingleRange/single_byte2402=== PAUSE TestParseSingleRange/single_byte2403=== RUN TestParseSingleRange/start_past_EOF2404=== PAUSE TestParseSingleRange/start_past_EOF2405=== RUN TestParseSingleRange/start_far_past_EOF2406=== PAUSE TestParseSingleRange/start_far_past_EOF2407=== CONT TestProxyWriteTimeout/narinfo2408=== CONT TestProxyWriteTimeout/unknown_size2409=== CONT TestProxyWriteTimeout/10_GiB_nar2410=== CONT TestProxyWriteTimeout/1_GiB_nar2411--- PASS: TestProxyWriteTimeout (0.08s)2412 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2413 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2414 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2415 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2416=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info24172026/10/01 09:27:28 INFO Received uploads request method=POST path=/2418=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key24192026/10/01 09:27:28 INFO Received complete multipart upload request method=POST path=/2420=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key24212026/10/01 09:27:28 INFO Received request for more parts method=POST path=/2422=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal24232026/10/01 09:27:28 INFO Received uploads request method=POST path=/2424--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)2425 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2426 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2427 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2428 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2429=== CONT TestIsValidUploadKey/narinfo2430=== CONT TestIsValidUploadKey/realisation_plus_in_output2431=== CONT TestIsValidUploadKey/realisation2432=== CONT TestIsValidUploadKey/build_log_equals2433=== CONT TestIsValidUploadKey/build_log_question_mark2434=== CONT TestIsValidUploadKey/build_log_plus_in_name2435=== CONT TestIsValidUploadKey/build_log_home-manager_file2436=== CONT TestIsValidUploadKey/build_log2437=== CONT TestIsValidUploadKey/listing2438=== CONT TestIsValidUploadKey/nar_plain2439=== CONT TestIsValidUploadKey/nar_xz2440=== CONT TestIsValidUploadKey/nar_zst2441=== CONT TestIsValidUploadKey/traversal_nar2442=== CONT TestIsValidUploadKey/nix-cache-info2443=== CONT TestIsValidUploadKey/traversal2444=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2445=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2446=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2447=== CONT TestIsValidUploadKey/index.html2448=== CONT TestIsValidUploadKey/empty_key2449=== CONT TestIsValidUploadKey/unknown_type2450=== CONT TestIsValidUploadKey/absolute2451--- PASS: TestIsValidUploadKey (0.08s)2452 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2453 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2454 --- PASS: TestIsValidUploadKey/realisation (0.00s)2455 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2456 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2457 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2458 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2459 --- PASS: TestIsValidUploadKey/build_log (0.00s)2460 --- PASS: TestIsValidUploadKey/listing (0.00s)2461 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2462 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2463 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2464 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2465 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2466 --- PASS: TestIsValidUploadKey/traversal (0.00s)2467 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2468 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2469 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2470 --- PASS: TestIsValidUploadKey/index.html (0.00s)2471 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2472 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2473 --- PASS: TestIsValidUploadKey/absolute (0.00s)2474=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure24752026/10/01 09:27:28 INFO Received uploads request method=POST path=/24762026/10/01 09:27:28 INFO All 1 paths already cached2477=== NAME TestClientIntegration2478 client_integration_test.go:312: Retrieved narinfo from S3:2479 StorePath: /build/TestClientIntegration1118162857/002/store/mr0fx18i8jra60g6fw3iynhakqy50xw7-test-file.txt2480 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2481 Compression: zstd2482 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12483 NarSize: 1522484 References: 2485 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk124862026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures2487 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2488 client_integration_test.go:313: Decompressed .ls content (64 bytes):2489 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2490 client_integration_test.go:316: Testing garbage collection...24912026-10-01 09:27:28.666 UTC [1614] ERROR: relation "goose_db_version" does not exist at character 3624922026-10-01 09:27:28.666 UTC [1614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2493--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.46s)2494=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24952026/10/01 09:27:28 INFO Received request for more parts method=POST path=/24962026/10/01 09:27:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures24972026/10/01 09:27:28 INFO Garbage collection started24982026/10/01 09:27:28 OK 20241026095416_initial_model.sql (26.21ms)24992026/10/01 09:27:28 INFO Aborted multipart uploads count=025002026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)25012026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period2502--- PASS: TestReadProxyInvalidPath (0.45s)2503=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25042026/10/01 09:27:28 INFO Received complete multipart upload request method=POST path=/25052026/10/01 09:27:28 OK 20251218171726_add_pins.sql (6.04ms)25062026-10-01 09:27:28.711 UTC [1671] ERROR: relation "goose_db_version" does not exist at character 3625072026-10-01 09:27:28.711 UTC [1671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25082026-10-01 09:27:28.711 UTC [1672] ERROR: relation "goose_db_version" does not exist at character 3625092026-10-01 09:27:28.711 UTC [1672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25102026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (5.43ms)25112026/10/01 09:27:28 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=025122026/10/01 09:27:28 OK 20260905000000_add_claims.sql (6.05ms)25132026-10-01 09:27:28.724 UTC [1684] ERROR: relation "goose_db_version" does not exist at character 3625142026-10-01 09:27:28.724 UTC [1684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25152026/10/01 09:27:28 INFO Vacuumed table table=pending_closures25162026/10/01 09:27:28 INFO Aborted multipart uploads count=025172026/10/01 09:27:28 OK 20241026095416_initial_model.sql (7.91ms)2518=== CONT TestServerTLSConfig/no_client_CA2519=== CONT TestServerTLSConfig/missing_CA_file2520=== CONT TestServerTLSConfig/not_a_PEM_file2521--- PASS: TestServerTLSConfig (0.00s)2522 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2523 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2524 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)25252026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)2526=== CONT TestPush_RejectsBadRequests/no_roots25272026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes2528=== CONT TestPush_RejectsBadRequests/bad_root25292026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes2530=== CONT TestPush_RejectsBadRequests/root_not_in_objects25312026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes2532=== CONT TestPush_RejectsBadRequests/no_objects25332026/10/01 09:27:28 INFO Vacuumed table table=pending_objects25342026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes2535--- PASS: TestPush_RejectsBadRequests (0.78s)2536 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2537 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2538 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2539 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2540=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows25412026/10/01 09:27:28 INFO Received push request method=POST path=/api/pushes25422026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads25432026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (4.55ms)25442026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.62ms)25452026/10/01 09:27:28 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=025462026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.22ms)25472026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000025482026/10/01 09:27:28 INFO Vacuumed table table=closures25492026/10/01 09:27:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2550--- PASS: TestReadProxy404 (0.44s)2551=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check25522026/10/01 09:27:28 INFO Uploading 6z0bq2j8g6z91n913wq6k4k452sqwcja-ca-test (144B)25532026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)25542026/10/01 09:27:28 OK 20241026095416_initial_model.sql (16.31ms)25552026/10/01 09:27:28 INFO Vacuumed table table=pending_closures25562026/10/01 09:27:28 OK 1_commit_pending_closure.sql (3.13ms)25572026/10/01 09:27:28 INFO Vacuumed table table=objects25582026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)25592026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.77ms)25602026/10/01 09:27:28 OK 2_object_stats_trigger.sql (2.35ms)25612026/10/01 09:27:28 INFO Vacuumed table table=pending_objects25622026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads25632026/10/01 09:27:28 OK 20241026095416_initial_model.sql (8.27ms)25642026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25652026/10/01 09:27:28 OK 3_commit_push.sql (1.3ms)25662026/10/01 09:27:28 goose: up to current file version: 325672026/10/01 09:27:28 WARN Failed to register uploaded object key=log/ggh1js85hs8spqjym59yvzj62va46c8s-ca-test.drv error="server returned 404: 404 page not found\n"25682026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25692026/10/01 09:27:28 WARN Failed to register uploaded object key=6z0bq2j8g6z91n913wq6k4k452sqwcja.ls error="server returned 404: 404 page not found\n"25702026/10/01 09:27:28 INFO Signed narinfos id=1 count=125712026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.53ms)25722026/10/01 09:27:28 INFO Uploading 1 narinfos25732026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.07ms)25742026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)25752026/10/01 09:27:28 INFO Vacuumed table table=closures25762026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.07ms)25772026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000025782026/10/01 09:27:28 INFO Vacuumed table table=objects25792026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)25802026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.13ms)25812026/10/01 09:27:28 OK 20251218171726_add_pins.sql (4.87ms)25822026/10/01 09:27:28 INFO Received complete push request method=POST path=/api/pushes/1/complete25832026/10/01 09:27:28 WARN Failed to register uploaded object key=6z0bq2j8g6z91n913wq6k4k452sqwcja.narinfo error="server returned 404: 404 page not found\n"25842026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.88ms)25852026/10/01 09:27:28 INFO Aborted multipart uploads count=025862026/10/01 09:27:28 OK 20260905000000_add_claims.sql (3.9ms)25872026/10/01 09:27:28 WARN Force mode enabled - objects will be deleted immediately without grace period25882026/10/01 09:27:28 OK 3_commit_push.sql (1.93ms)25892026/10/01 09:27:28 goose: up to current file version: 325902026/10/01 09:27:28 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=025912026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)25922026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.65ms)25932026/10/01 09:27:28 INFO Vacuumed table table=pending_closures25942026/10/01 09:27:28 INFO Upload complete. (100ms)25952026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.6ms)25962026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000025972026/10/01 09:27:28 OK 20260905000000_add_claims.sql (4.96ms)25982026/10/01 09:27:28 INFO Vacuumed table table=pending_objects2599=== NAME TestClientCADerivations2600 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations867817050/001/store/6z0bq2j8g6z91n913wq6k4k452sqwcja-ca-test2601 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2602 Compression: zstd2603 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n26042026/10/01 09:27:28 INFO Vacuumed table table=multipart_uploads2605 NarSize: 1442606 References: 2607 Deriver: /build/TestClientCADerivations867817050/001/store/ggh1js85hs8spqjym59yvzj62va46c8s-ca-test.drv2608 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2609 client_ca_test.go:185: Checking for realisation files in S3...26102026/10/01 09:27:28 OK 1_commit_pending_closure.sql (3.1ms)26112026/10/01 09:27:28 INFO Vacuumed table table=closures2612 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2613 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache26142026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.92ms)26152026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.93ms)26162026/10/01 09:27:28 INFO Vacuumed table table=objects26172026/10/01 09:27:28 OK 3_commit_push.sql (1.98ms)26182026/10/01 09:27:28 goose: up to current file version: 32619--- PASS: TestPushDedupSurvivesConcurrentGC (0.64s)2620=== CONT TestClientErrorHandling/InvalidStorePath26212026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (3.07ms)26222026/10/01 09:27:28 goose: successfully migrated database to version: 202609231200002623=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2624=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2625=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2626=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2627=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2628=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2629=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2630=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2631=== CONT TestClientErrorHandling/ServerNotAvailable26322026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.91ms)26332026/10/01 09:27:28 OK 2_object_stats_trigger.sql (2.21ms)26342026/10/01 09:27:28 OK 3_commit_push.sql (2.45ms)26352026/10/01 09:27:28 goose: up to current file version: 32636=== CONT TestClientErrorHandling/InvalidAuthToken26372026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures26382026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures26392026/10/01 09:27:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)26402026/10/01 09:27:28 INFO Uploading h6znfnci4rsvr5hspz0h4sr0c2m8hkf3-a (216B)26412026/10/01 09:27:28 INFO Uploading 35v2f1hc8naa1yfnrzjkphff05108i7z-shared-dep (136B)2642--- PASS: TestReadProxyHead (0.38s)2643=== CONT TestResolveDBConnectionString/flag_wins2644=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2645=== CONT TestResolveDBConnectionString/nothing_configured2646=== CONT TestResolveDBConnectionString/missing_file_is_an_error2647=== CONT TestResolveDBConnectionString/file_when_flag_empty2648=== CONT TestCacheConfigHandler/full_config,_no_issuer2649=== CONT TestCacheConfigHandler/no_signing_keys2650=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2651=== CONT TestCacheConfigHandler/no_cache_url_configured2652--- PASS: TestCacheConfigHandler (0.00s)2653 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2654 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2655 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2656 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2657=== CONT TestIsValidCachePath/narinfo2658=== CONT TestIsValidCachePath/index.html2659=== CONT TestIsValidCachePath/short_hash2660=== CONT TestIsValidCachePath/invalid_char_u2661=== CONT TestIsValidCachePath/invalid_char_e2662=== CONT TestIsValidCachePath/traversal_in_middle2663=== CONT TestIsValidCachePath/random_path2664=== CONT TestIsValidCachePath/traversal_parent2665=== CONT TestIsValidCachePath/wrong_extension2666=== CONT TestIsValidCachePath/nar_uncompressed2667=== CONT TestIsValidCachePath/leading_slash2668=== CONT TestIsValidCachePath/nix-cache-info2669=== CONT TestIsValidCachePath/empty2670=== CONT TestIsValidCachePath/realisation2671=== CONT TestIsValidCachePath/log2672=== CONT TestIsValidCachePath/nar_zst2673=== CONT TestIsValidCachePath/nar_xz2674=== CONT TestIsValidCachePath/ls2675=== CONT TestIsValidCachePath/nar_bz22676=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2677--- PASS: TestResolveDBConnectionString (0.00s)2678 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2679 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2680 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2681 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2682 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2683=== CONT TestParseSingleRange/none2684=== CONT TestParseSingleRange/open-ended2685=== CONT TestParseSingleRange/start_far_past_EOF2686=== CONT TestParseSingleRange/start_past_EOF26872026/10/01 09:27:28 WARN Failed to register uploaded object key=4q8g3n8lwvkaxqj0ad1ynxs7avygf0fb.ls error="server returned 404: 404 page not found\n"2688--- PASS: TestIsValidCachePath (0.00s)2689 --- PASS: TestIsValidCachePath/narinfo (0.00s)2690 --- PASS: TestIsValidCachePath/index.html (0.00s)2691 --- PASS: TestIsValidCachePath/short_hash (0.00s)2692 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2693 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2694 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2695 --- PASS: TestIsValidCachePath/random_path (0.00s)2696 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2697 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2698 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2699 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2700 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2701 --- PASS: TestIsValidCachePath/empty (0.00s)2702 --- PASS: TestIsValidCachePath/realisation (0.00s)2703 --- PASS: TestIsValidCachePath/log (0.00s)2704 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2705 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2706 --- PASS: TestIsValidCachePath/ls (0.00s)2707 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2708 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2709=== CONT TestParseSingleRange/single_byte2710=== CONT TestParseSingleRange/suffix_exceeds_size27112026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/0xx8makb81yjmhdc64f38y86dbrzph7n0sfm5kpv06yhxz4dpkwh.nar.zst error="server returned 404: 404 page not found\n"2712=== CONT TestParseSingleRange/suffix2713=== CONT TestParseSingleRange/end_clamped_to_size27142026/10/01 09:27:28 WARN Failed to register uploaded object key=35v2f1hc8naa1yfnrzjkphff05108i7z.ls error="server returned 404: 404 page not found\n"2715=== CONT TestParseSingleRange/malformed_both_empty2716=== CONT TestParseSingleRange/closed2717=== CONT TestParseSingleRange/malformed_end_before_start2718=== CONT TestParseSingleRange/unknown_unit2719=== CONT TestParseSingleRange/multi-range_ignored2720=== CONT TestParseSingleRange/malformed_no_dash2721--- PASS: TestParseSingleRange (0.00s)2722 --- PASS: TestParseSingleRange/none (0.00s)2723 --- PASS: TestParseSingleRange/open-ended (0.00s)2724 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2725 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2726 --- PASS: TestParseSingleRange/single_byte (0.00s)2727 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2728 --- PASS: TestParseSingleRange/suffix (0.00s)2729 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2730 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2731 --- PASS: TestParseSingleRange/closed (0.00s)2732 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2733 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2734 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2735 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2736=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token27372026/10/01 09:27:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"27382026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign27392026/10/01 09:27:28 WARN Failed to register uploaded object key=h6znfnci4rsvr5hspz0h4sr0c2m8hkf3.ls error="server returned 404: 404 page not found\n"27402026/10/01 09:27:28 INFO Signed narinfos id=1 count=227412026/10/01 09:27:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign27422026/10/01 09:27:28 INFO Signed narinfos id=2 count=227432026/10/01 09:27:28 INFO Uploading 4 narinfos2744=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2745=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27462026/10/01 09:27:28 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]2747=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27482026/10/01 09:27:28 WARN Authentication failed token_preview=eyJhbGciOi...8EIi_ATvKA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]27492026/10/01 09:27:28 WARN Failed to register uploaded object key=35v2f1hc8naa1yfnrzjkphff05108i7z.narinfo error="server returned 404: 404 page not found\n"27502026/10/01 09:27:28 WARN Failed to register uploaded object key=h6znfnci4rsvr5hspz0h4sr0c2m8hkf3.narinfo error="server returned 404: 404 page not found\n"2751--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2752 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2753 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2754 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2755 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)27562026/10/01 09:27:28 WARN Failed to register uploaded object key=4q8g3n8lwvkaxqj0ad1ynxs7avygf0fb.narinfo error="server returned 404: 404 page not found\n"27572026/10/01 09:27:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete27582026/10/01 09:27:28 WARN Failed to register uploaded object key=35v2f1hc8naa1yfnrzjkphff05108i7z.narinfo error="server returned 404: 404 page not found\n"27592026/10/01 09:27:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2760--- PASS: TestReadProxyNarStreaming (0.40s)27612026/10/01 09:27:28 INFO Completed upload id=127622026/10/01 09:27:28 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete27632026/10/01 09:27:28 INFO Completed upload id=227642026/10/01 09:27:28 INFO Upload complete. (83ms)2765=== NAME TestClientFallsBackToClosures2766 client_pushes_test.go:112: Retrieved narinfo from S3:2767 StorePath: /build/TestClientFallsBackToClosures1647053723/001/store/35v2f1hc8naa1yfnrzjkphff05108i7z-shared-dep2768 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2769 Compression: zstd2770 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822771 NarSize: 1362772 References: 2773 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2774 client_pushes_test.go:112: Retrieved narinfo from S3:27752026/10/01 09:27:28 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/present2776 StorePath: /build/TestClientFallsBackToClosures1647053723/001/store/h6znfnci4rsvr5hspz0h4sr0c2m8hkf3-a2777 URL: nar/0xx8makb81yjmhdc64f38y86dbrzph7n0sfm5kpv06yhxz4dpkwh.nar.zst2778 Compression: zstd2779 NarHash: sha256:0xx8makb81yjmhdc64f38y86dbrzph7n0sfm5kpv06yhxz4dpkwh2780 NarSize: 2162781 References: /build/TestClientFallsBackToClosures1647053723/001/store/35v2f1hc8naa1yfnrzjkphff05108i7z-shared-dep2782 CA: text:sha256:0cn1k4m86yc78zy34w1wx85dlswxsf7d75almipz5wqaigrxqcws2783 client_pushes_test.go:112: Retrieved narinfo from S3:2784 StorePath: /build/TestClientFallsBackToClosures1647053723/001/store/4q8g3n8lwvkaxqj0ad1ynxs7avygf0fb-b2785 URL: nar/0xx8makb81yjmhdc64f38y86dbrzph7n0sfm5kpv06yhxz4dpkwh.nar.zst2786 Compression: zstd2787 NarHash: sha256:0xx8makb81yjmhdc64f38y86dbrzph7n0sfm5kpv06yhxz4dpkwh2788 NarSize: 2162789 References: /build/TestClientFallsBackToClosures1647053723/001/store/35v2f1hc8naa1yfnrzjkphff05108i7z-shared-dep2790 CA: text:sha256:0cn1k4m86yc78zy34w1wx85dlswxsf7d75almipz5wqaigrxqcws27912026-10-01 09:27:28.838 UTC [1915] ERROR: relation "goose_db_version" does not exist at character 3627922026-10-01 09:27:28.838 UTC [1915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27932026/10/01 09:27:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDVmMzgzMWItMmY2OS00OWVlLWIxNzEtNjdjMTY3M2ZhNmEwLjM4M2JlY2Y5LWQzNTItNDU2MS04NjFmLWRkMjg4ODNlZjlmOXgxNzkwODQ2ODQ4Mjc3ODcyMzU1 parts=1227942026/10/01 09:27:28 INFO Received uploads request method=POST path=/api/pending_closures2795--- PASS: TestClientFallsBackToClosures (0.72s)27962026/10/01 09:27:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"27972026/10/01 09:27:28 WARN mTLS auth: bound subjects configured but subject DN unavailable27982026/10/01 09:27:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2799--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.42s)28002026-10-01 09:27:28.843 UTC [1916] ERROR: relation "goose_db_version" does not exist at character 3628012026-10-01 09:27:28.843 UTC [1916] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2802--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.13s)2803--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.85s)28042026/10/01 09:27:28 OK 20241026095416_initial_model.sql (7.8ms)28052026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)28062026/10/01 09:27:28 OK 20251218171726_add_pins.sql (3.04ms)28072026/10/01 09:27:28 OK 20241026095416_initial_model.sql (7.93ms)28082026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)28092026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)28102026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.53ms)28112026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.89ms)28122026-10-01 09:27:28.862 UTC [1942] ERROR: relation "goose_db_version" does not exist at character 3628132026-10-01 09:27:28.862 UTC [1942] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28142026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (1.49ms)28152026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)2816--- PASS: TestService_ReadScope_PublicByDefault (0.42s)28172026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.66ms)28182026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000028192026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.28ms)28202026/10/01 09:27:28 OK 20260905000000_add_claims.sql (4.26ms)28212026/10/01 09:27:28 OK 2_object_stats_trigger.sql (1.76ms)28222026/10/01 09:27:28 OK 3_commit_push.sql (1.4ms)28232026/10/01 09:27:28 goose: up to current file version: 328242026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (2.74ms)28252026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (2.22ms)28262026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000028272026/10/01 09:27:28 OK 1_commit_pending_closure.sql (2.64ms)28282026/10/01 09:27:28 OK 2_object_stats_trigger.sql (850.78µs)28292026/10/01 09:27:28 OK 3_commit_push.sql (1.14ms)28302026/10/01 09:27:28 goose: up to current file version: 32831--- PASS: TestGCBugBareHashReferences (0.70s)28322026/10/01 09:27:28 OK 20241026095416_initial_model.sql (11.26ms)28332026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (935.57µs)28342026/10/01 09:27:28 OK 20251218171726_add_pins.sql (2.21ms)28352026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (2.66ms)28362026-10-01 09:27:28.888 UTC [1987] ERROR: relation "goose_db_version" does not exist at character 3628372026-10-01 09:27:28.888 UTC [1987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2838--- PASS: TestService_ReadAuthMiddleware (0.42s)28392026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.21ms)2840=== NAME TestClientCADerivations2841 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2842 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2843 error: binary cache 's3://bucket58?endpoint=http://localhost:43021®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations867817050/001/store'2844 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 128452026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (1.42ms)28462026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.13ms)28472026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000028482026/10/01 09:27:28 OK 1_commit_pending_closure.sql (1.85ms)2849--- PASS: TestClientCADerivations (0.95s)28502026/10/01 09:27:28 OK 2_object_stats_trigger.sql (754.81µs)28512026/10/01 09:27:28 OK 3_commit_push.sql (581.88µs)28522026/10/01 09:27:28 goose: up to current file version: 328532026/10/01 09:27:28 OK 20241026095416_initial_model.sql (6.66ms)28542026/10/01 09:27:28 OK 20251210153512_drop_unused_gin_index.sql (901.13µs)28552026/10/01 09:27:28 OK 20251218171726_add_pins.sql (1.93ms)28562026/10/01 09:27:28 OK 20260628120000_add_object_size_and_stats.sql (2.05ms)28572026/10/01 09:27:28 OK 20260905000000_add_claims.sql (2.08ms)28582026/10/01 09:27:28 OK 20260920000000_drop_claims.sql (1.45ms)28592026/10/01 09:27:28 OK 20260923120000_add_pushes.sql (1.08ms)28602026/10/01 09:27:28 goose: successfully migrated database to version: 2026092312000028612026/10/01 09:27:28 OK 1_commit_pending_closure.sql (1.46ms)28622026/10/01 09:27:28 OK 2_object_stats_trigger.sql (612.72µs)2863--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)28642026/10/01 09:27:28 OK 3_commit_push.sql (644.1µs)28652026/10/01 09:27:28 goose: up to current file version: 328662026/10/01 09:27:28 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3197206501/001/proxy.sock28672026/10/01 09:27:28 INFO Starting HTTP server address=127.0.0.1:4204128682026/10/01 09:27:28 WARN mTLS auth: subject not in bound subjects subject="CN=someone"28692026/10/01 09:27:28 INFO Shutdown signal received, draining in-flight requests timeout=10s2870--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.34s)28712026/10/01 09:27:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.233711ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2872=== RUN TestService_RequireScope_OIDC/builder_may_write2873=== PAUSE TestService_RequireScope_OIDC/builder_may_write2874=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2875=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2876=== RUN TestService_RequireScope_OIDC/ops_may_admin2877=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2878=== RUN TestService_RequireScope_OIDC/ops_may_not_write2879=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2880=== RUN TestService_RequireScope_OIDC/reader_may_not_write2881=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2882=== RUN TestService_RequireScope_OIDC/static_token_may_admin2883=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2884=== RUN TestService_RequireScope_OIDC/static_token_may_write2885=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2886=== RUN TestService_RequireScope_OIDC/reader_may_read2887=== PAUSE TestService_RequireScope_OIDC/reader_may_read2888=== RUN TestService_RequireScope_OIDC/writer_implies_read2889=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2890=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2891=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2892=== CONT TestService_RequireScope_OIDC/builder_may_write2893=== CONT TestService_RequireScope_OIDC/ops_may_admin2894=== CONT TestService_RequireScope_OIDC/static_token_may_admin2895=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2896=== CONT TestService_RequireScope_OIDC/writer_implies_read2897=== CONT TestService_RequireScope_OIDC/ops_may_not_write2898=== CONT TestService_RequireScope_OIDC/reader_may_read2899=== CONT TestService_RequireScope_OIDC/reader_may_not_write2900=== CONT TestService_RequireScope_OIDC/static_token_may_write2901=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2902--- PASS: TestService_RequireScope_OIDC (0.44s)2903 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2904 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2905 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2906 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2907 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2908 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2909 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2910 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2911 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2912 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2913--- PASS: TestReadProxyNarinfo (0.36s)29142026/10/01 09:27:29 INFO Received uploads request method=POST path=/api/pending_closures29152026/10/01 09:27:29 INFO Aborted multipart uploads count=029162026/10/01 09:27:29 WARN Force mode enabled - objects will be deleted immediately without grace period29172026/10/01 09:27:29 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=029182026/10/01 09:27:29 INFO Vacuumed table table=pending_closures29192026/10/01 09:27:29 INFO Vacuumed table table=pending_objects29202026/10/01 09:27:29 INFO Vacuumed table table=multipart_uploads29212026/10/01 09:27:29 INFO Vacuumed table table=closures29222026/10/01 09:27:29 INFO Received uploads request method=POST path=/api/pending_closures29232026/10/01 09:27:29 INFO Vacuumed table table=objects29242026/10/01 09:27:29 INFO Aborted multipart uploads count=029252026/10/01 09:27:29 WARN Force mode enabled - objects will be deleted immediately without grace period29262026/10/01 09:27:29 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=029272026/10/01 09:27:29 INFO Vacuumed table table=pending_closures29282026/10/01 09:27:29 INFO Vacuumed table table=pending_objects29292026/10/01 09:27:29 INFO Vacuumed table table=multipart_uploads29302026/10/01 09:27:29 INFO Vacuumed table table=closures29312026/10/01 09:27:29 INFO Vacuumed table table=objects2932--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2933 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)2934 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.32s)29352026/10/01 09:27:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2936=== NAME TestOrphanedObjectsGCStressTest2937 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains29382026/10/01 09:27:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.966789ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2939 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion29402026/10/01 09:27:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2941--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2942 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2943 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2944 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)29452026/10/01 09:27:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=829.99146ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2946=== NAME TestOrphanedObjectsGCStressTest2947 orphaned_objects_gc_test.go:509: Stress test completed successfully:2948 orphaned_objects_gc_test.go:510: - Active objects preserved: 202949 orphaned_objects_gc_test.go:511: - Objects deleted: 2102950 orphaned_objects_gc_test.go:512: - Total GC'd: 2102951--- PASS: TestOrphanedObjectsGCStressTest (3.05s)29522026/10/01 09:27:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.5254881s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29532026/10/01 09:27:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=029542026/10/01 09:27:30 INFO Received create pin request method=POST path=/api/pins/myapp29552026/10/01 09:27:30 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC782992138/001/store/kf2cg3ki9nmdxw64dbnqijqv3k9lhgnx-pinned-file.txt narinfo_key=kf2cg3ki9nmdxw64dbnqijqv3k9lhgnx.narinfo29562026/10/01 09:27:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures29572026/10/01 09:27:30 INFO Garbage collection started29582026/10/01 09:27:30 INFO Aborted multipart uploads count=029592026/10/01 09:27:30 WARN Force mode enabled - objects will be deleted immediately without grace period29602026/10/01 09:27:30 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=029612026/10/01 09:27:30 INFO Vacuumed table table=pending_closures29622026/10/01 09:27:30 INFO Vacuumed table table=pending_objects29632026/10/01 09:27:30 INFO Vacuumed table table=multipart_uploads29642026/10/01 09:27:30 INFO Vacuumed table table=closures29652026/10/01 09:27:30 INFO Vacuumed table table=objects29662026/10/01 09:27:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02967=== NAME TestClientIntegration2968 client_integration_test.go:323: Objects in database after GC:2969 client_integration_test.go:323: Successfully deleted all objects with GC --force2970--- PASS: TestClientIntegration (2.80s)29712026/10/01 09:27:31 WARN Rate limiter enabled after throttle name=s3-test rate=529722026/10/01 09:27:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2973=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2974 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102975 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002976--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.78s)29772026/10/01 09:27:31 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-config29782026/10/01 09:27:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.772624ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29792026/10/01 09:27:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.137127ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2980=== NAME TestPinProtectsFromGC2981 client_integration_test.go:840: Pin successfully protected closure from garbage collection2982--- PASS: TestPinProtectsFromGC (4.92s)29832026/10/01 09:27:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.123222ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29842026/10/01 09:27:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.648698758s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29852026/10/01 09:27:35 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"29862026/10/01 09:27:35 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-config29872026/10/01 09:27:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.452508ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29882026/10/01 09:27:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.470035ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29892026/10/01 09:27:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=846.197378ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29902026/10/01 09:27:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.664767614s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29912026/10/01 09:27:38 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_closures29922026/10/01 09:27:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.006026ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29932026/10/01 09:27:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=398.76785ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29942026/10/01 09:27:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=741.401813ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29952026/10/01 09:27:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.496598878s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2996--- PASS: TestClientErrorHandling (0.00s)2997 --- PASS: TestClientErrorHandling/InvalidStorePath (0.32s)2998 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.41s)2999 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.47s)3000PASS3001{"timestamp":"2026-10-01T09:27:41.230507304Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:42576","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(386)"}30022026-10-01 09:27:41.570 UTC [129] LOG: received smart shutdown request30032026-10-01 09:27:41.574 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 130042026-10-01 09:27:41.586 UTC [134] LOG: shutting down30052026-10-01 09:27:41.587 UTC [134] LOG: checkpoint starting: shutdown immediate30062026-10-01 09:27:43.229 UTC [134] LOG: checkpoint complete: wrote 10857 buffers (66.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 23 recycled; write=0.259 s, sync=1.334 s, total=1.644 s; sync files=27304, longest=0.003 s, average=0.001 s; distance=378292 kB, estimate=378292 kB; lsn=0/188D2F88, redo lsn=0/188D2F8830072026-10-01 09:27:43.305 UTC [129] LOG: database system is shut down3008Running OIDC tests...3009=== RUN TestAudienceForIssuer3010=== PAUSE TestAudienceForIssuer3011=== RUN TestGlobMatch3012=== PAUSE TestGlobMatch3013=== RUN TestValidateToken_ValidToken3014=== PAUSE TestValidateToken_ValidToken3015=== RUN TestValidateToken_WrongAudience3016=== PAUSE TestValidateToken_WrongAudience3017=== RUN TestValidateToken_Expired3018=== PAUSE TestValidateToken_Expired3019=== RUN TestValidateToken_BoundClaimsMismatch3020=== PAUSE TestValidateToken_BoundClaimsMismatch3021=== RUN TestValidateToken_BoundSubjectMismatch3022=== PAUSE TestValidateToken_BoundSubjectMismatch3023=== RUN TestValidateToken_MultipleProviders3024=== PAUSE TestValidateToken_MultipleProviders3025=== RUN TestValidateToken_NoMatchingProvider3026=== PAUSE TestValidateToken_NoMatchingProvider3027=== RUN TestValidateToken_KubernetesServiceAccount3028=== PAUSE TestValidateToken_KubernetesServiceAccount3029=== RUN TestNewValidator_KubernetesRequiresCA3030=== PAUSE TestNewValidator_KubernetesRequiresCA3031=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3032=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3033=== RUN TestPins_ReservedForMatchingRule3034=== PAUSE TestPins_ReservedForMatchingRule3035=== RUN TestPins_TopLevelShorthand3036=== PAUSE TestPins_TopLevelShorthand3037=== RUN TestPins_ConfigValidation3038=== PAUSE TestPins_ConfigValidation3039=== RUN TestScopes_LegacyProviderDefaultsToWrite3040=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3041=== RUN TestScopes_Rules3042=== PAUSE TestScopes_Rules3043=== RUN TestScopes_ConfigValidation3044=== PAUSE TestScopes_ConfigValidation3045=== CONT TestAudienceForIssuer3046=== CONT TestPins_ConfigValidation3047=== CONT TestPins_ReservedForMatchingRule3048--- PASS: TestAudienceForIssuer (0.00s)3049=== CONT TestValidateToken_NoMatchingProvider3050=== CONT TestValidateToken_MultipleProviders3051=== CONT TestValidateToken_BoundSubjectMismatch3052=== CONT TestValidateToken_BoundClaimsMismatch3053=== CONT TestValidateToken_Expired3054=== CONT TestValidateToken_WrongAudience3055=== CONT TestValidateToken_ValidToken3056=== CONT TestGlobMatch3057=== RUN TestGlobMatch/foo_foo3058=== PAUSE TestGlobMatch/foo_foo3059=== RUN TestGlobMatch/foo_bar3060=== PAUSE TestGlobMatch/foo_bar3061=== RUN TestGlobMatch/*_3062=== PAUSE TestGlobMatch/*_3063=== RUN TestGlobMatch/*_anything3064=== PAUSE TestGlobMatch/*_anything3065=== RUN TestGlobMatch/foo*_foo3066=== PAUSE TestGlobMatch/foo*_foo3067=== RUN TestGlobMatch/foo*_foobar3068=== PAUSE TestGlobMatch/foo*_foobar3069=== RUN TestGlobMatch/foo*_bar3070=== PAUSE TestGlobMatch/foo*_bar3071=== RUN TestGlobMatch/*bar_bar3072=== PAUSE TestGlobMatch/*bar_bar3073=== RUN TestGlobMatch/*bar_foobar3074=== PAUSE TestGlobMatch/*bar_foobar3075=== RUN TestGlobMatch/*bar_foo3076=== PAUSE TestGlobMatch/*bar_foo3077=== RUN TestGlobMatch/foo*bar_foobar3078=== PAUSE TestGlobMatch/foo*bar_foobar3079=== RUN TestGlobMatch/foo*bar_foo123bar3080=== PAUSE TestGlobMatch/foo*bar_foo123bar3081=== RUN TestGlobMatch/foo*bar_foobarbaz3082=== PAUSE TestGlobMatch/foo*bar_foobarbaz3083=== RUN TestGlobMatch/*/*_foo/bar3084=== PAUSE TestGlobMatch/*/*_foo/bar3085=== RUN TestGlobMatch/*/*_foo3086=== PAUSE TestGlobMatch/*/*_foo3087=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3088=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3089=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03090=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03091=== RUN TestGlobMatch/refs/*/main_refs/heads/main3092=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3093=== RUN TestGlobMatch/fo?_foo3094=== PAUSE TestGlobMatch/fo?_foo3095=== RUN TestGlobMatch/fo?_fo3096=== PAUSE TestGlobMatch/fo?_fo3097=== RUN TestGlobMatch/fo?_fooo3098=== PAUSE TestGlobMatch/fo?_fooo3099=== RUN TestGlobMatch/?oo_foo3100=== PAUSE TestGlobMatch/?oo_foo3101=== RUN TestGlobMatch/?oo_boo3102=== PAUSE TestGlobMatch/?oo_boo3103=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3104=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3105=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3106=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3107=== CONT TestGlobMatch/foo_foo3108=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3109=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3110=== CONT TestGlobMatch/?oo_boo3111=== CONT TestGlobMatch/?oo_foo3112=== CONT TestGlobMatch/fo?_fooo3113=== CONT TestGlobMatch/fo?_fo3114=== CONT TestGlobMatch/fo?_foo3115=== CONT TestGlobMatch/refs/*/main_refs/heads/main3116=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03117=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3118=== CONT TestGlobMatch/*/*_foo3119=== CONT TestGlobMatch/*/*_foo/bar3120=== CONT TestGlobMatch/foo*bar_foobarbaz3121=== CONT TestGlobMatch/foo*bar_foo123bar3122=== CONT TestGlobMatch/foo*bar_foobar3123=== CONT TestGlobMatch/*bar_foo3124=== CONT TestGlobMatch/*bar_foobar3125=== CONT TestGlobMatch/*bar_bar3126=== CONT TestGlobMatch/foo*_bar3127=== CONT TestGlobMatch/foo*_foobar3128=== CONT TestGlobMatch/foo*_foo3129=== CONT TestGlobMatch/*_anything3130=== CONT TestGlobMatch/*_3131=== CONT TestGlobMatch/foo_bar3132=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3133=== CONT TestPins_TopLevelShorthand3134=== CONT TestNewValidator_KubernetesRequiresCA3135=== CONT TestScopes_Rules3136=== CONT TestValidateToken_KubernetesServiceAccount3137=== CONT TestScopes_ConfigValidation3138=== CONT TestScopes_LegacyProviderDefaultsToWrite3139--- PASS: TestPins_ConfigValidation (0.00s)3140--- PASS: TestGlobMatch (0.00s)3141 --- PASS: TestGlobMatch/foo_foo (0.00s)3142 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3143 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3144 --- PASS: TestGlobMatch/?oo_boo (0.00s)3145 --- PASS: TestGlobMatch/?oo_foo (0.00s)3146 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3147 --- PASS: TestGlobMatch/fo?_fo (0.00s)3148 --- PASS: TestGlobMatch/fo?_foo (0.00s)3149 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3150 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3151 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3152 --- PASS: TestGlobMatch/*/*_foo (0.00s)3153 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3154 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3155 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3156 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3157 --- PASS: TestGlobMatch/*bar_foo (0.00s)3158 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3159 --- PASS: TestGlobMatch/*bar_bar (0.00s)3160 --- PASS: TestGlobMatch/foo*_bar (0.00s)3161 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3162 --- PASS: TestGlobMatch/foo*_foo (0.00s)3163 --- PASS: TestGlobMatch/*_anything (0.00s)3164 --- PASS: TestGlobMatch/*_ (0.00s)3165 --- PASS: TestGlobMatch/foo_bar (0.00s)3166--- PASS: TestScopes_ConfigValidation (0.00s)31672026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45543/oidc31682026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34609/oidc3169--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)3170--- PASS: TestPins_ReservedForMatchingRule (0.03s)31712026/10/01 09:27:45 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233172--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)31732026/10/01 09:27:45 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:417753174--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)31752026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38381/oidc3176--- PASS: TestValidateToken_Expired (0.06s)31772026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43999/oidc3178--- PASS: TestPins_TopLevelShorthand (0.07s)31792026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42339/oidc3180--- PASS: TestValidateToken_ValidToken (0.08s)31812026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41325/oidc3182--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)31832026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34983/oidc31842026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41471/oidc3185--- PASS: TestValidateToken_WrongAudience (0.09s)3186--- PASS: TestScopes_Rules (0.09s)31872026/10/01 09:27:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32871/oidc3188--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)31892026/10/01 09:27:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41879/oidc3190--- PASS: TestValidateToken_NoMatchingProvider (0.16s)31912026/10/01 09:27:45 http: TLS handshake error from 127.0.0.1:39272: remote error: tls: bad certificate3192--- PASS: TestNewValidator_KubernetesRequiresCA (0.17s)31932026/10/01 09:27:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33639/oidc31942026/10/01 09:27:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35307/oidc3195--- PASS: TestValidateToken_MultipleProviders (0.22s)3196PASS3197Running hook tests...3198=== RUN TestSendPathsEmpty3199=== PAUSE TestSendPathsEmpty3200=== RUN TestQueueEnqueueAndFetch3201=== PAUSE TestQueueEnqueueAndFetch3202=== RUN TestQueueDeduplication3203=== PAUSE TestQueueDeduplication3204=== RUN TestQueueRemove3205=== PAUSE TestQueueRemove3206=== RUN TestQueueFetchBatchLimit3207=== PAUSE TestQueueFetchBatchLimit3208=== RUN TestQueueRetryMovesToBack3209=== PAUSE TestQueueRetryMovesToBack3210=== RUN TestQueueFetchRemoveLifecycle3211=== PAUSE TestQueueFetchRemoveLifecycle3212=== RUN TestQueueConcurrentWriters3213=== PAUSE TestQueueConcurrentWriters3214=== RUN TestQueueRemoveLargeClosure3215=== PAUSE TestQueueRemoveLargeClosure3216=== RUN TestServerClientIntegration3217=== PAUSE TestServerClientIntegration3218=== RUN TestServerQueueError3219=== PAUSE TestServerQueueError3220=== RUN TestGetListenerSocketActivation3221 server_test.go:210: === RUN TestGetListenerSocketActivation3222 --- PASS: TestGetListenerSocketActivation (0.00s)3223 PASS3224 3225--- PASS: TestGetListenerSocketActivation (0.01s)3226=== RUN TestDrainIsolatesPoisonPath3227=== PAUSE TestDrainIsolatesPoisonPath3228=== RUN TestRunNotBlockedByPoisonHead3229=== PAUSE TestRunNotBlockedByPoisonHead3230=== RUN TestDrainGivesUpWhenServerDown3231=== PAUSE TestDrainGivesUpWhenServerDown3232=== RUN TestFailedPathPrunedByLaterClosure3233=== PAUSE TestFailedPathPrunedByLaterClosure3234=== RUN TestWorkerUploadsAndRemoves3235=== PAUSE TestWorkerUploadsAndRemoves3236=== RUN TestWorkerSkipsGCdPaths3237=== PAUSE TestWorkerSkipsGCdPaths3238=== RUN TestWorkerPrunesClosureDeps3239=== PAUSE TestWorkerPrunesClosureDeps3240=== RUN TestDrainTimeout3241=== PAUSE TestDrainTimeout3242=== CONT TestSendPathsEmpty3243=== CONT TestServerQueueError3244=== CONT TestDrainGivesUpWhenServerDown3245--- PASS: TestSendPathsEmpty (0.00s)3246=== CONT TestQueueFetchBatchLimit3247=== CONT TestQueueRemove3248=== CONT TestQueueDeduplication32492026/10/01 09:27:45 ERROR Failed to queue paths error="permission denied" count=13250=== CONT TestQueueEnqueueAndFetch3251=== CONT TestWorkerUploadsAndRemoves3252=== CONT TestDrainTimeout3253=== CONT TestWorkerPrunesClosureDeps3254=== CONT TestWorkerSkipsGCdPaths3255=== CONT TestRunNotBlockedByPoisonHead3256=== CONT TestDrainIsolatesPoisonPath3257=== CONT TestQueueRemoveLargeClosure3258=== CONT TestServerClientIntegration3259=== CONT TestFailedPathPrunedByLaterClosure3260=== CONT TestQueueConcurrentWriters3261=== CONT TestQueueFetchRemoveLifecycle3262=== CONT TestQueueRetryMovesToBack3263--- PASS: TestServerQueueError (0.00s)3264--- PASS: TestServerClientIntegration (0.00s)32652026/10/01 09:27:45 INFO Uploading batch count=132662026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=132672026/10/01 09:27:45 INFO Upload queue status pending=332682026/10/01 09:27:45 INFO Upload queue status pending=232692026/10/01 09:27:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1998604203/002/nonexistent32702026/10/01 09:27:45 INFO Uploading batch count=432712026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=432722026/10/01 09:27:45 INFO Uploading batch count=232732026/10/01 09:27:45 INFO Upload queue status pending=232742026/10/01 09:27:45 INFO Uploading batch count=132752026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=132762026/10/01 09:27:45 INFO Uploading batch count=232772026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=232782026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3397743571/002/a32792026/10/01 09:27:45 INFO Uploading batch count=132802026/10/01 09:27:45 INFO Uploading batch count=13281--- PASS: TestQueueEnqueueAndFetch (0.02s)32822026/10/01 09:27:45 INFO Uploading batch count=13283--- PASS: TestQueueFetchBatchLimit (0.02s)3284--- PASS: TestQueueDeduplication (0.02s)32852026/10/01 09:27:45 INFO Upload queue status pending=232862026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3213502273/002/bbb32872026/10/01 09:27:45 INFO Uploading batch count=232882026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3397743571/002/b32892026/10/01 09:27:45 INFO Uploading batch count=13290--- PASS: TestQueueFetchRemoveLifecycle (0.01s)32912026/10/01 09:27:45 INFO Uploading batch count=232922026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=232932026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3397743571/002/c32942026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3397743571/002/d3295--- PASS: TestQueueRemove (0.02s)3296--- PASS: TestQueueRetryMovesToBack (0.02s)32972026/10/01 09:27:45 INFO Uploading batch count=232982026/10/01 09:27:45 INFO Uploading batch count=132992026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=133002026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=233012026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3397743571/002/e3302--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)33032026/10/01 09:27:45 INFO Uploading batch count=133042026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=133052026/10/01 09:27:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3397743571/002/f33062026/10/01 09:27:45 INFO Uploading batch count=133072026/10/01 09:27:45 ERROR Upload failed error="upload failed" count=133082026/10/01 09:27:45 ERROR Drain finished with paths left in queue remaining=1033092026/10/01 09:27:45 ERROR Drain finished with paths left in queue remaining=13310--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3311--- PASS: TestDrainIsolatesPoisonPath (0.02s)3312--- PASS: TestWorkerSkipsGCdPaths (0.03s)3313--- PASS: TestWorkerPrunesClosureDeps (0.03s)3314--- PASS: TestWorkerUploadsAndRemoves (0.04s)3315--- PASS: TestQueueRemoveLargeClosure (0.07s)33162026/10/01 09:27:45 ERROR Upload failed error="context deadline exceeded" count=233172026/10/01 09:27:45 ERROR Drain finished with paths left in queue remaining=43318--- PASS: TestDrainTimeout (0.22s)3319--- PASS: TestQueueConcurrentWriters (0.48s)33202026/10/01 09:27:46 INFO Uploading batch count=133212026/10/01 09:27:46 INFO Uploading batch count=133222026/10/01 09:27:46 INFO Uploading batch count=133232026/10/01 09:27:46 ERROR Upload failed error="upload failed" count=133242026/10/01 09:27:46 INFO Uploading batch count=133252026/10/01 09:27:46 ERROR Upload failed error="upload failed" count=133262026/10/01 09:27:46 INFO Uploading batch count=133272026/10/01 09:27:46 ERROR Upload failed error="upload failed" count=133282026/10/01 09:27:46 INFO Uploading batch count=133292026/10/01 09:27:46 ERROR Upload failed error="upload failed" count=133302026/10/01 09:27:46 ERROR Drain finished with paths left in queue remaining=13331--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3332PASS