niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #302
· 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 TestEncodeNixBase32WithRealHash97--- PASS: TestEncodeNixBase32WithRealHash (0.00s)98=== CONT TestFileTokenEmpty99=== CONT TestShellSplit100=== CONT TestSetClientTLSDoesNotMutateDefaultTransport101--- PASS: TestShellSplit (0.00s)102=== CONT TestSetClientTLS103=== CONT TestClientSignaturesByStorePath104--- PASS: TestClientSignaturesByStorePath (0.00s)105=== CONT TestFileTokenMissing106=== CONT TestStreamPushReportsSignatures107=== CONT TestStreamPushRequestLine108=== CONT TestPathInfoHashCompatibility109=== CONT TestStreamPushGivesUpOnDeadServer110=== CONT TestStreamPushIsolatesFailures111=== CONT TestStreamPushBatchesUnderLoad112=== CONT TestStreamPushReportsEveryPath113=== CONT TestSetClientTLSErrors114=== CONT TestShellSplitErrors115=== CONT TestStaticToken116=== CONT TestScriptTokenEmptyCommand117=== CONT TestParsePathInfoJSON118=== RUN TestParsePathInfoJSON/Nix_format119=== CONT TestPathInfoCACompatibility120=== CONT TestScriptTokenScriptFails121=== CONT TestDoWithRetry_BodyReplayedViaGetBody122=== CONT TestScriptTokenBadJSON123=== CONT TestResolveStorePath124=== CONT TestScriptTokenEmptyToken125=== CONT TestScriptTokenCachesUntilRefresh126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess128=== CONT TestRateLimiterFeedback129--- PASS: TestFileTokenEmpty (0.00s)130=== CONT TestFileTokenReadsAndCaches131=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)132=== CONT TestParsePathInfoJSONMultiplePaths133=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1342026/10/01 08:28:09 ERROR Upload failed error="connection refused" count=201352026/10/01 08:28:09 ERROR Server seems unavailable, giving up on batch untried=17136=== RUN TestPathInfoCACompatibility/null_ca_field137=== PAUSE TestParsePathInfoJSON/Nix_format138--- PASS: TestFileTokenMissing (0.00s)139--- PASS: TestShellSplitErrors (0.00s)140--- PASS: TestStaticToken (0.00s)141--- PASS: TestScriptTokenEmptyCommand (0.00s)142=== RUN TestParsePathInfoJSON/Lix_format1432026/10/01 08:28:09 ERROR Upload failed error="bad path" count=3144=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1452026/10/01 08:28:09 WARN Rate limiter enabled after throttle name=server-test rate=5146--- PASS: TestScriptTokenScriptFails (0.00s)147=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths148--- PASS: TestStreamPushIsolatesFailures (0.00s)149=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== CONT TestDumpPathWriterError151=== CONT TestGetStorePathHash152--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)153=== CONT TestDumpPathSingleFile154=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)155=== CONT TestEncodeNixBase32156=== RUN TestRateLimiterFeedback/429_enables_limiter157=== RUN TestEncodeNixBase32/test_string_hash158=== RUN TestGetStorePathHash/valid_store_path159=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon160=== RUN TestSetClientTLSErrors/missing_cert_file161--- PASS: TestFileTokenReadsAndCaches (0.00s)162--- PASS: TestResolveStorePath (0.01s)163=== CONT TestFilterOversizedClosures164=== RUN TestFilterOversizedClosures/no_limit_keeps_everything165=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything166=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped167=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped168=== RUN TestFilterOversizedClosures/all_closures_skipped169=== PAUSE TestFilterOversizedClosures/all_closures_skipped170=== CONT TestPartSizeForNAR171=== RUN TestPartSizeForNAR/zero_stays_at_minimum172=== CONT TestUploadMultipart_PartsInParallel1732026/10/01 08:28:09 ERROR Upload failed error=boom count=11742026/10/01 08:28:09 ERROR Upload failed error=boom count=11752026/10/01 08:28:09 WARN Rate limiter enabled after throttle name=server-test rate=5176=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum1772026/10/01 08:28:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41001178=== RUN TestPartSizeForNAR/small_stays_at_minimum179--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)180=== PAUSE TestEncodeNixBase32/test_string_hash181=== PAUSE TestPathInfoCACompatibility/null_ca_field182=== PAUSE TestParsePathInfoJSON/Lix_format183=== PAUSE TestGetStorePathHash/valid_store_path184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon185=== PAUSE TestRateLimiterFeedback/429_enables_limiter186=== RUN TestSetClientTLS/rejects_connection_without_client_cert187=== CONT TestCaseHackSuffix188=== PAUSE TestSetClientTLSErrors/missing_cert_file189=== CONT TestRegisterUploadedObjectReusesConnections190=== CONT TestDumpPathMatchesNix191=== PAUSE TestPartSizeForNAR/small_stays_at_minimum192--- PASS: TestDoServerRequestAttachesToken (0.02s)193--- PASS: TestStreamPushReportsEveryPath (0.01s)194=== CONT TestConvertHashToNix32195=== RUN TestConvertHashToNix32/SRI_format_to_Nix32196=== RUN TestRateLimiterFeedback/503_enables_limiter197=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum198--- PASS: TestStreamPushReportsSignatures (0.01s)199=== CONT TestUploadMultipart_SupersededByPeer200=== RUN TestUploadMultipart_SupersededByPeer/exists201--- PASS: TestScriptTokenEmptyToken (0.01s)202--- PASS: TestScriptTokenBadJSON (0.01s)203=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths204=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths205--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)206 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)207 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)208--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)209=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2102026/10/01 08:28:09 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=2000211=== CONT TestFilterOversizedClosures/all_closures_skipped2122026/10/01 08:28:09 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=50213=== PAUSE TestRateLimiterFeedback/503_enables_limiter214=== RUN TestSetClientTLSErrors/missing_key_file215=== PAUSE TestSetClientTLSErrors/missing_key_file216=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert217=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter218=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter219=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter220=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter2212026/10/01 08:28:09 WARN Rate limiter backed off name=server-test rate=5222=== CONT TestRateLimiterFeedback/429_enables_limiter2232026/10/01 08:28:09 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41001224=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter225=== RUN TestSetClientTLSErrors/missing_ca_file226=== PAUSE TestSetClientTLSErrors/missing_ca_file227=== RUN TestSetClientTLSErrors/invalid_ca_file228=== PAUSE TestSetClientTLSErrors/invalid_ca_file229--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)230=== CONT TestRateLimiterFeedback/503_enables_limiter231=== RUN TestParsePathInfoJSON/empty_input232=== CONT TestFilterOversizedClosures/no_limit_keeps_everything233=== RUN TestGetStorePathHash/basename_without_hyphen_should_error234=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32235=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestUploadMultipart_SupersededByPeer/exists237=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238=== RUN TestEncodeNixBase32/empty_input239=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA240=== RUN TestPathInfoCACompatibility/old_string_format_-_text241=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter242=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts243=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts244=== RUN TestPartSizeForNAR/1_TiB245=== PAUSE TestPartSizeForNAR/1_TiB246=== RUN TestPartSizeForNAR/5_TiB_S3_max_object247=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object248=== RUN TestPartSizeForNAR/capped_at_5_GiB249=== PAUSE TestPartSizeForNAR/capped_at_5_GiB250=== RUN TestUploadMultipart_SupersededByPeer/missing251=== PAUSE TestUploadMultipart_SupersededByPeer/missing252=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI253=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512254=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512255=== CONT TestSetClientTLSErrors/missing_ca_file256=== PAUSE TestParsePathInfoJSON/empty_input257=== RUN TestParsePathInfoJSON/whitespace_only258=== PAUSE TestParsePathInfoJSON/whitespace_only2592026/10/01 08:28:09 WARN Rate limiter enabled after throttle name=server-test rate=5260=== RUN TestParsePathInfoJSON/invalid_JSON2612026/10/01 08:28:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34331262=== PAUSE TestParsePathInfoJSON/invalid_JSON263--- PASS: TestFilterOversizedClosures (0.00s)264 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)265 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)266 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)267=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error268=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2692026/10/01 08:28:09 WARN Rate limiter backed off name=server-test rate=5270=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error271=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error272=== PAUSE TestEncodeNixBase32/empty_input273=== CONT TestUploadMultipart_SupersededByPeer/exists2742026/10/01 08:28:09 WARN Rate limiter enabled after throttle name=server-test rate=5275=== CONT TestPartSizeForNAR/small_stays_at_minimum2762026/10/01 08:28:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:38463277=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512278=== CONT TestUploadMultipart_SupersededByPeer/missing2792026/10/01 08:28:09 WARN Rate limiter backed off name=server-test rate=5280=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI281=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon282=== CONT TestParsePathInfoJSON/invalid_JSON283=== CONT TestParsePathInfoJSON/whitespace_only284=== CONT TestParsePathInfoJSON/empty_input285=== CONT TestParsePathInfoJSON/Lix_format286=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)287=== CONT TestPartSizeForNAR/5_TiB_S3_max_object288=== CONT TestPartSizeForNAR/1_TiB289=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts290=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum291=== CONT TestEncodeNixBase32/test_string_hash292=== CONT TestEncodeNixBase32/empty_input293=== CONT TestSetClientTLSErrors/missing_key_file294=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text295=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive296=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive297=== RUN TestPathInfoCACompatibility/new_structured_format_-_text298=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text299=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method300=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method301=== CONT TestPathInfoCACompatibility/null_ca_field302=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA303=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive304=== RUN TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestPartSizeForNAR/capped_at_5_GiB306=== CONT TestPathInfoCACompatibility/old_string_format_-_text307=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error308=== CONT TestGetStorePathHash/valid_store_path309=== RUN TestConvertHashToNix32/already_Nix32_format310=== PAUSE TestConvertHashToNix32/already_Nix32_format311=== RUN TestConvertHashToNix32/invalid_format312=== PAUSE TestConvertHashToNix32/invalid_format313=== CONT TestConvertHashToNix32/SRI_format_to_Nix32314=== CONT TestGetStorePathHash/basename_without_hyphen_should_error315=== CONT TestPartSizeForNAR/zero_stays_at_minimum316=== CONT TestSetClientTLSErrors/missing_cert_file317=== CONT TestParsePathInfoJSON/Nix_format318=== CONT TestConvertHashToNix32/invalid_format319=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error320=== CONT TestPathInfoCACompatibility/new_structured_format_-_text321=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method322=== PAUSE TestSetClientTLS/preserves_debug_logging_transport323=== CONT TestSetClientTLS/rejects_connection_without_client_cert324=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA325=== CONT TestSetClientTLS/preserves_debug_logging_transport326=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error327--- PASS: TestRateLimiterFeedback (0.04s)328 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)329 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)330 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)331 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)332=== CONT TestConvertHashToNix32/already_Nix32_format333--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)334=== CONT TestSetClientTLSErrors/invalid_ca_file335--- PASS: TestEncodeNixBase32 (0.03s)336 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)337 --- PASS: TestEncodeNixBase32/empty_input (0.00s)338--- PASS: TestPathInfoHashCompatibility (0.04s)339 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)340 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)341 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)342 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)343--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)344 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)346--- PASS: TestPathInfoCACompatibility (0.04s)347 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)349 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)350 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)351 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)352--- PASS: TestConvertHashToNix32 (0.03s)353 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)354 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)355 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)356--- PASS: TestGetStorePathHash (0.04s)357 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)358 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)361--- PASS: TestPartSizeForNAR (0.03s)362 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)364 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)365 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)366 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369--- PASS: TestParsePathInfoJSON (0.04s)370 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)371 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)372 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)373 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)374 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)375--- PASS: TestSetClientTLSErrors (0.04s)376 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380--- PASS: TestDumpPathSingleFile (0.05s)381--- PASS: TestStreamPushRequestLine (0.06s)3822026/10/01 08:28:09 http: TLS handshake error from 127.0.0.1:39688: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.05s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.11s)391--- PASS: TestDumpPathMatchesNix (0.08s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres4239414104/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/postgres4239414104/data -l logfile start422423/build/postgres4239414104:5432 - no response4242026-10-01 08:28:11.471 UTC [127] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 08:28:11.471 UTC [127] LOG: listening on Unix socket "/build/postgres4239414104/.s.PGSQL.5432"4262026-10-01 08:28:11.476 UTC [134] LOG: database system was shut down at 2026-10-01 08:28:11 UTC4272026-10-01 08:28:11.479 UTC [127] LOG: database system is ready to accept connections428/build/postgres4239414104:5432 - accepting connections429{"timestamp":"2026-10-01T08:28:11.773329254Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"385065c8-de6e-4d33-80b3-72c92bedf1f4","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(389)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 08:28:11.962 UTC [562] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 08:28:11.962 UTC [562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 08:28:11 OK 20241026095416_initial_model.sql (7.02ms)4742026/10/01 08:28:11 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)4752026/10/01 08:28:11 OK 20251218171726_add_pins.sql (2.02ms)4762026/10/01 08:28:11 OK 20260628120000_add_object_size_and_stats.sql (1.94ms)4772026/10/01 08:28:11 OK 20260905000000_add_claims.sql (2.72ms)4782026/10/01 08:28:11 OK 20260920000000_drop_claims.sql (1.54ms)4792026/10/01 08:28:11 OK 20260923120000_add_pushes.sql (1.13ms)4802026/10/01 08:28:11 goose: successfully migrated database to version: 202609231200004812026/10/01 08:28:11 OK 1_commit_pending_closure.sql (1.62ms)4822026/10/01 08:28:11 OK 2_object_stats_trigger.sql (1.45ms)4832026/10/01 08:28:11 OK 3_commit_push.sql (701.53µs)4842026/10/01 08:28:11 goose: up to current file version: 34852026/10/01 08:28:12 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 08:28:12 INFO lead: released remote=192.0.2.1:12344872026/10/01 08:28:12 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 08:28:12 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 08:28:12.729 UTC [573] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 08:28:12.729 UTC [573] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 08:28:12 OK 20241026095416_initial_model.sql (6.66ms)4962026/10/01 08:28:12 OK 20251210153512_drop_unused_gin_index.sql (774.31µs)4972026/10/01 08:28:12 OK 20251218171726_add_pins.sql (3.49ms)4982026/10/01 08:28:12 OK 20260628120000_add_object_size_and_stats.sql (2.57ms)4992026/10/01 08:28:12 OK 20260905000000_add_claims.sql (2.34ms)5002026/10/01 08:28:12 OK 20260920000000_drop_claims.sql (1.39ms)5012026/10/01 08:28:12 OK 20260923120000_add_pushes.sql (953.66µs)5022026/10/01 08:28:12 goose: successfully migrated database to version: 202609231200005032026/10/01 08:28:12 OK 1_commit_pending_closure.sql (1.35ms)5042026/10/01 08:28:12 OK 2_object_stats_trigger.sql (587µs)5052026/10/01 08:28:12 OK 3_commit_push.sql (538.39µs)5062026/10/01 08:28:12 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestGCTaskStore_StartNew535=== PAUSE TestGCTaskStore_StartNew536=== RUN TestGCTaskStore_DeduplicateSameParams537=== PAUSE TestGCTaskStore_DeduplicateSameParams538=== RUN TestGCTaskStore_ConflictDifferentParams539=== PAUSE TestGCTaskStore_ConflictDifferentParams540=== RUN TestGCTaskStore_GetEmpty541=== PAUSE TestGCTaskStore_GetEmpty542=== RUN TestGCTaskStore_GetReturnsLatest543=== PAUSE TestGCTaskStore_GetReturnsLatest544=== RUN TestGCTaskStore_CompletedAllowsNewTask545=== PAUSE TestGCTaskStore_CompletedAllowsNewTask546=== RUN TestGCTaskStore_PhaseUpdates547=== PAUSE TestGCTaskStore_PhaseUpdates548=== RUN TestGCTaskStore_Fail549=== PAUSE TestGCTaskStore_Fail550=== RUN TestGracefulShutdownDrainsInflight551=== PAUSE TestGracefulShutdownDrainsInflight552=== RUN TestService_healthCheckHandler553=== PAUSE TestService_healthCheckHandler554=== RUN TestService_readinessHandler555=== PAUSE TestService_readinessHandler556=== RUN TestGenerateLandingPage557=== PAUSE TestGenerateLandingPage558=== RUN TestCacheConfigHandlerMaxNarSize559=== PAUSE TestCacheConfigHandlerMaxNarSize560=== RUN TestCreatePendingClosureRejectsOversizedNAR561=== PAUSE TestCreatePendingClosureRejectsOversizedNAR562=== RUN TestNARDeduplicationMetadataUploadBug563=== PAUSE TestNARDeduplicationMetadataUploadBug564=== RUN TestMetricsInventory565=== PAUSE TestMetricsInventory566=== RUN TestService_NativeMTLS567=== PAUSE TestService_NativeMTLS568=== RUN TestServerTLSConfig569=== PAUSE TestServerTLSConfig570=== RUN TestMultipartCleanup571=== PAUSE TestMultipartCleanup572=== RUN TestObjectStatsTrigger573=== PAUSE TestObjectStatsTrigger574=== RUN TestOrphanedObjectsGC575=== PAUSE TestOrphanedObjectsGC576=== RUN TestOrphanedObjectsGCStressTest577=== PAUSE TestOrphanedObjectsGCStressTest578=== RUN TestCreatePin_ReservedPins579=== PAUSE TestCreatePin_ReservedPins580=== RUN TestParseSingleRange581=== PAUSE TestParseSingleRange582=== RUN TestProxyHeadersOnlyTrustedOnSocket583=== PAUSE TestProxyHeadersOnlyTrustedOnSocket584=== RUN TestIsValidCachePath585=== PAUSE TestIsValidCachePath586=== RUN TestReadProxyNarinfo587=== PAUSE TestReadProxyNarinfo588=== RUN TestReadProxyNarinfoAlreadyDecompressed589=== PAUSE TestReadProxyNarinfoAlreadyDecompressed590=== RUN TestReadProxyNarStreaming591=== PAUSE TestReadProxyNarStreaming592=== RUN TestReadProxy404593=== PAUSE TestReadProxy404594=== RUN TestReadProxyInvalidPath595=== PAUSE TestReadProxyInvalidPath596=== RUN TestReadProxyHead597=== PAUSE TestReadProxyHead598=== RUN TestReadProxyConditionalGet599=== PAUSE TestReadProxyConditionalGet600=== RUN TestReadProxyRootRedirectsToIndexHTML601=== PAUSE TestReadProxyRootRedirectsToIndexHTML602=== RUN TestReadProxyDisabled603=== PAUSE TestReadProxyDisabled604=== RUN TestReadRedirectNar605=== PAUSE TestReadRedirectNar606=== RUN TestReadRedirectKeepsNarinfoProxied607=== PAUSE TestReadRedirectKeepsNarinfoProxied608=== RUN TestReadProxyRangeRequest609=== PAUSE TestReadProxyRangeRequest610=== RUN TestReadRedirectUsesPublicS3URL611=== PAUSE TestReadRedirectUsesPublicS3URL612=== RUN TestPush_OverlappingRootsStoreOneRowPerKey613=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey614=== RUN TestPush_CompleteCommitsEveryRoot615=== PAUSE TestPush_CompleteCommitsEveryRoot616=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit617=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit618=== RUN TestPush_RejectsBadRequests619=== PAUSE TestPush_RejectsBadRequests620=== RUN TestPush_SignsNarinfosOfItsPendingObjects621=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects622=== RUN TestRedundantMultipartUpload623=== PAUSE TestRedundantMultipartUpload624=== RUN TestCompleteMultipartUpload_ErrorButObjectExists625=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists626=== RUN TestCompletedNarNotReofferedAcrossClosures627=== PAUSE TestCompletedNarNotReofferedAcrossClosures628=== RUN TestPresignedUploadRegisteredBeforeCommit629=== PAUSE TestPresignedUploadRegisteredBeforeCommit630=== RUN TestService_Rustfstest631=== PAUSE TestService_Rustfstest632=== RUN TestParseSize633=== PAUSE TestParseSize634=== RUN TestSkippedUploadsHandler635=== PAUSE TestSkippedUploadsHandler636=== RUN TestSystemdListenerNotActivated637--- PASS: TestSystemdListenerNotActivated (0.00s)638=== RUN TestWatchdogBeatsWhenHealthy639--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)640=== RUN TestWatchdogSkipsWhenUnhealthy6412026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:28:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"651--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)652=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle653=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle654=== RUN TestProxyWriteTimeout655=== PAUSE TestProxyWriteTimeout656=== RUN TestIsValidUploadKey657=== PAUSE TestIsValidUploadKey658=== RUN TestUploadHandlersRejectInvalidKeys659=== PAUSE TestUploadHandlersRejectInvalidKeys660=== RUN TestUploadHandlersRejectOversizedBody661=== PAUSE TestUploadHandlersRejectOversizedBody662=== RUN TestService_cleanupPendingClosuresHandler663=== PAUSE TestService_cleanupPendingClosuresHandler664=== RUN TestService_createPendingClosureHandler665=== PAUSE TestService_createPendingClosureHandler666=== RUN TestService_verifyS3Integrity667=== PAUSE TestService_verifyS3Integrity668=== RUN TestCompleteMultipartUnregistered669=== PAUSE TestCompleteMultipartUnregistered670=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT671=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT672=== CONT TestService_AuthMiddleware673=== CONT TestMetricsInventory674=== CONT TestReadRedirectUsesPublicS3URL675=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT676=== CONT TestCompleteMultipartUnregistered677=== CONT TestService_verifyS3Integrity678=== CONT TestService_createPendingClosureHandler679=== CONT TestService_cleanupPendingClosuresHandler680=== CONT TestUploadHandlersRejectOversizedBody681=== CONT TestUploadHandlersRejectInvalidKeys682=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info683=== CONT TestIsValidUploadKey684=== CONT TestProxyWriteTimeout685=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle686=== CONT TestSkippedUploadsHandler687=== CONT TestParseSize688=== CONT TestService_Rustfstest689=== CONT TestPresignedUploadRegisteredBeforeCommit690=== CONT TestCompletedNarNotReofferedAcrossClosures691=== CONT TestCompleteMultipartUpload_ErrorButObjectExists692=== CONT TestRedundantMultipartUpload693=== CONT TestPush_SignsNarinfosOfItsPendingObjects694=== CONT TestPush_RejectsBadRequests695=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit696=== CONT TestPush_CompleteCommitsEveryRoot697--- PASS: TestParseSize (0.00s)698=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info699=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal700=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal701=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key702=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key703=== RUN TestProxyWriteTimeout/narinfo704=== CONT TestPush_OverlappingRootsStoreOneRowPerKey705=== RUN TestIsValidUploadKey/narinfo706=== PAUSE TestIsValidUploadKey/narinfo707=== PAUSE TestProxyWriteTimeout/narinfo708=== RUN TestIsValidUploadKey/nar_zst709=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key710=== RUN TestProxyWriteTimeout/1_GiB_nar7112026/10/01 08:28:13 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000712=== PAUSE TestIsValidUploadKey/nar_zst713=== RUN TestIsValidUploadKey/nar_xz714=== PAUSE TestIsValidUploadKey/nar_xz715=== RUN TestIsValidUploadKey/nar_plain716=== PAUSE TestIsValidUploadKey/nar_plain717=== RUN TestIsValidUploadKey/listing718=== PAUSE TestIsValidUploadKey/listing719=== RUN TestIsValidUploadKey/build_log720=== PAUSE TestIsValidUploadKey/build_log721=== RUN TestIsValidUploadKey/build_log_home-manager_file722=== PAUSE TestIsValidUploadKey/build_log_home-manager_file723=== RUN TestIsValidUploadKey/build_log_plus_in_name724=== PAUSE TestIsValidUploadKey/build_log_plus_in_name725=== RUN TestIsValidUploadKey/build_log_question_mark726=== PAUSE TestIsValidUploadKey/build_log_question_mark727=== RUN TestIsValidUploadKey/build_log_equals728=== PAUSE TestIsValidUploadKey/build_log_equals729=== RUN TestIsValidUploadKey/realisation730=== PAUSE TestIsValidUploadKey/realisation731=== RUN TestIsValidUploadKey/realisation_plus_in_output732=== PAUSE TestIsValidUploadKey/realisation_plus_in_output733=== RUN TestIsValidUploadKey/nix-cache-info734=== PAUSE TestIsValidUploadKey/nix-cache-info735=== RUN TestIsValidUploadKey/index.html736=== PAUSE TestIsValidUploadKey/index.html737=== RUN TestIsValidUploadKey/narinfo_key,_nar_type738=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type739=== RUN TestIsValidUploadKey/nar_key,_narinfo_type740=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type741=== RUN TestIsValidUploadKey/listing_key,_narinfo_type742=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type743=== RUN TestIsValidUploadKey/traversal744=== PAUSE TestIsValidUploadKey/traversal745=== RUN TestIsValidUploadKey/traversal_nar746=== PAUSE TestIsValidUploadKey/traversal_nar747=== RUN TestIsValidUploadKey/absolute748=== PAUSE TestIsValidUploadKey/absolute749=== RUN TestIsValidUploadKey/empty_key750=== PAUSE TestIsValidUploadKey/empty_key751=== RUN TestIsValidUploadKey/unknown_type752=== PAUSE TestIsValidUploadKey/unknown_type753=== CONT TestReadProxyNarinfoAlreadyDecompressed754=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key755=== PAUSE TestProxyWriteTimeout/1_GiB_nar756=== CONT TestReadProxyRangeRequest757=== RUN TestProxyWriteTimeout/10_GiB_nar758=== PAUSE TestProxyWriteTimeout/10_GiB_nar759=== RUN TestProxyWriteTimeout/unknown_size760=== PAUSE TestProxyWriteTimeout/unknown_size761=== CONT TestReadRedirectKeepsNarinfoProxied762--- PASS: TestSkippedUploadsHandler (0.06s)763=== CONT TestReadRedirectNar764=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure765=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure766=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart767=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart768=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts769=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts770=== CONT TestReadProxyDisabled7712026-10-01 08:28:13.218 UTC [639] ERROR: relation "goose_db_version" does not exist at character 367722026-10-01 08:28:13.218 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026-10-01 08:28:13.265 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367742026-10-01 08:28:13.265 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026-10-01 08:28:13.297 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367762026-10-01 08:28:13.297 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-10-01 08:28:13.306 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367782026-10-01 08:28:13.306 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026/10/01 08:28:13 OK 20241026095416_initial_model.sql (25.49ms)7802026/10/01 08:28:13 OK 20241026095416_initial_model.sql (29.92ms)7812026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)7822026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)7832026/10/01 08:28:13 OK 20241026095416_initial_model.sql (25.65ms)7842026/10/01 08:28:13 OK 20251218171726_add_pins.sql (6.93ms)7852026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.29ms)7862026-10-01 08:28:13.341 UTC [647] ERROR: relation "goose_db_version" does not exist at character 367872026-10-01 08:28:13.341 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7882026-10-01 08:28:13.341 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367892026-10-01 08:28:13.341 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (6.51ms)7912026/10/01 08:28:13 OK 20251218171726_add_pins.sql (8.03ms)7922026/10/01 08:28:13 OK 20241026095416_initial_model.sql (18.66ms)7932026/10/01 08:28:13 OK 20251218171726_add_pins.sql (10.42ms)7942026/10/01 08:28:13 OK 20260905000000_add_claims.sql (5.7ms)7952026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.87ms)7962026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (6.21ms)7972026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.75ms)7982026/10/01 08:28:13 OK 20260905000000_add_claims.sql (15.76ms)7992026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (15.05ms)8002026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200008012026/10/01 08:28:13 OK 20251218171726_add_pins.sql (17.01ms)8022026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (21.76ms)8032026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (6.26ms)8042026/10/01 08:28:13 OK 1_commit_pending_closure.sql (6.44ms)8052026/10/01 08:28:13 OK 2_object_stats_trigger.sql (3.43ms)8062026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (3.88ms)8072026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200008082026/10/01 08:28:13 OK 20260905000000_add_claims.sql (9.91ms)8092026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (12.16ms)8102026/10/01 08:28:13 OK 3_commit_push.sql (3.77ms)8112026/10/01 08:28:13 goose: up to current file version: 38122026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.61ms)8132026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (6.53ms)8142026-10-01 08:28:13.385 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368152026-10-01 08:28:13.385 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.82ms)8172026-10-01 08:28:13.386 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368182026-10-01 08:28:13.386 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026/10/01 08:28:13 OK 20241026095416_initial_model.sql (29.46ms)8202026/10/01 08:28:13 OK 3_commit_push.sql (2.85ms)8212026/10/01 08:28:13 goose: up to current file version: 38222026/10/01 08:28:13 OK 20260905000000_add_claims.sql (8.06ms)8232026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (4.62ms)8242026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200008252026/10/01 08:28:13 OK 20241026095416_initial_model.sql (20.89ms)8262026-10-01 08:28:13.391 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368272026-10-01 08:28:13.391 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.41ms)8292026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.76ms)8302026-10-01 08:28:13.395 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368312026-10-01 08:28:13.395 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (5.36ms)8332026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (4.42ms)8342026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200008352026/10/01 08:28:13 OK 1_commit_pending_closure.sql (7.42ms)8362026/10/01 08:28:13 OK 20251218171726_add_pins.sql (6.54ms)8372026/10/01 08:28:13 OK 2_object_stats_trigger.sql (3.56ms)8382026/10/01 08:28:13 OK 1_commit_pending_closure.sql (5.51ms)8392026/10/01 08:28:13 OK 20251218171726_add_pins.sql (7.29ms)8402026/10/01 08:28:13 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"841--- PASS: TestService_AuthMiddleware (0.40s)842=== CONT TestReadProxyRootRedirectsToIndexHTML8432026/10/01 08:28:13 OK 3_commit_push.sql (15.64ms)8442026/10/01 08:28:13 goose: up to current file version: 38452026/10/01 08:28:13 OK 2_object_stats_trigger.sql (18.67ms)8462026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (18.53ms)8472026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (23.03ms)8482026/10/01 08:28:13 OK 3_commit_push.sql (1.55ms)8492026/10/01 08:28:13 goose: up to current file version: 38502026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures8512026/10/01 08:28:13 OK 20241026095416_initial_model.sql (20.81ms)8522026/10/01 08:28:13 OK 20260905000000_add_claims.sql (5.14ms)8532026/10/01 08:28:13 OK 20260905000000_add_claims.sql (5.27ms)8542026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.18ms)8552026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.71ms)8562026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (5.04ms)8572026-10-01 08:28:13.435 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368582026-10-01 08:28:13.435 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (3.97ms)8602026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200008612026/10/01 08:28:13 OK 20251218171726_add_pins.sql (5.26ms)8622026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (3.64ms)8632026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200008642026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.75ms)8652026/10/01 08:28:13 OK 20241026095416_initial_model.sql (17.94ms)8662026-10-01 08:28:13.437 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368672026-10-01 08:28:13.437 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8682026-10-01 08:28:13.438 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368692026-10-01 08:28:13.438 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/10/01 08:28:13 OK 20241026095416_initial_model.sql (15.13ms)8712026/10/01 08:28:13 OK 1_commit_pending_closure.sql (4.21ms)8722026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)8732026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)8742026/10/01 08:28:13 OK 1_commit_pending_closure.sql (4.2ms)8752026-10-01 08:28:13.441 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368762026-10-01 08:28:13.441 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8772026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.58ms)8782026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.93ms)8792026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)8802026/10/01 08:28:13 OK 3_commit_push.sql (1.42ms)8812026/10/01 08:28:13 goose: up to current file version: 38822026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.12ms)8832026-10-01 08:28:13.444 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368842026-10-01 08:28:13.444 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.06ms)8862026/10/01 08:28:13 OK 3_commit_push.sql (1.7ms)8872026/10/01 08:28:13 goose: up to current file version: 38882026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.94ms)8892026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures8902026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.39ms)8922026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures8932026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.32ms)894--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.44s)895=== CONT TestReadProxyConditionalGet8962026-10-01 08:28:13.448 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368972026-10-01 08:28:13.448 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026-10-01 08:28:13.448 UTC [662] ERROR: relation "goose_db_version" does not exist at character 368992026-10-01 08:28:13.448 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9002026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.23ms)9012026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.92ms)9022026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)9032026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (3.03ms)9042026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200009052026-10-01 08:28:13.452 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369062026-10-01 08:28:13.452 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026-10-01 08:28:13.452 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369082026-10-01 08:28:13.452 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (6.3ms)9102026-10-01 08:28:13.453 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369112026-10-01 08:28:13.453 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9122026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.61ms)9132026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.72ms)9142026-10-01 08:28:13.456 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369152026-10-01 08:28:13.456 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9162026/10/01 08:28:13 OK 1_commit_pending_closure.sql (4.42ms)9172026-10-01 08:28:13.457 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369182026-10-01 08:28:13.457 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.16ms)9202026/10/01 08:28:13 OK 20241026095416_initial_model.sql (11.11ms)9212026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.54ms)9222026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.46ms)9232026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.95ms)9242026/10/01 08:28:13 OK 3_commit_push.sql (1.54ms)9252026/10/01 08:28:13 goose: up to current file version: 39262026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)9272026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.85ms)9282026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.66ms)9292026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200009302026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.4ms)9312026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200009322026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.63ms)9332026-10-01 08:28:13.463 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369342026-10-01 08:28:13.463 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026-10-01 08:28:13.463 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369362026-10-01 08:28:13.463 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9372026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.98ms)9382026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200009392026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)9402026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.32ms)9412026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.5ms)9422026/10/01 08:28:13 OK 20241026095416_initial_model.sql (13.47ms)9432026/10/01 08:28:13 OK 20251218171726_add_pins.sql (5.14ms)9442026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.98ms)9452026/10/01 08:28:13 OK 2_object_stats_trigger.sql (3.13ms)9462026/10/01 08:28:13 OK 2_object_stats_trigger.sql (3.05ms)9472026/10/01 08:28:13 OK 1_commit_pending_closure.sql (4.91ms)9482026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.79ms)9492026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)9502026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)9512026/10/01 08:28:13 OK 3_commit_push.sql (1.74ms)9522026/10/01 08:28:13 goose: up to current file version: 39532026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.52ms)9542026/10/01 08:28:13 OK 3_commit_push.sql (1.75ms)9552026/10/01 08:28:13 goose: up to current file version: 39562026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)9572026/10/01 08:28:13 OK 20241026095416_initial_model.sql (11.92ms)9582026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.34ms)9592026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)9602026/10/01 08:28:13 OK 20241026095416_initial_model.sql (11.56ms)9612026/10/01 08:28:13 OK 3_commit_push.sql (1.44ms)9622026/10/01 08:28:13 goose: up to current file version: 39632026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)9642026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.12ms)9652026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.62ms)9662026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.9ms)9672026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)9682026/10/01 08:28:13 OK 20241026095416_initial_model.sql (11.9ms)9692026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.18ms)9702026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.62ms)9712026/10/01 08:28:13 OK 20251218171726_add_pins.sql (5.07ms)9722026/10/01 08:28:13 OK 20241026095416_initial_model.sql (13.04ms)9732026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)9742026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.42ms)9752026/10/01 08:28:13 OK 20241026095416_initial_model.sql (14.44ms)9762026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)9772026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.79ms)9782026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.82ms)9792026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.41ms)9802026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.44ms)9812026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.94ms)9822026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.87ms)9832026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)9842026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)9852026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.25ms)9862026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.76ms)9872026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200009882026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)9892026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.72ms)9902026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.5ms)9912026/10/01 08:28:13 OK 20241026095416_initial_model.sql (11.33ms)9922026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.48ms)9932026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.92ms)9942026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.96ms)9952026/10/01 08:28:13 OK 20241026095416_initial_model.sql (12.56ms)9962026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.16ms)9972026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.72ms)9982026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200009992026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)10002026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.39ms)10012026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.47ms)10022026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.23ms)10032026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)10042026/10/01 08:28:13 OK 20251218171726_add_pins.sql (3.88ms)10052026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.93ms)10062026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.6ms)10072026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)10082026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)10092026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)10102026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.78ms)10112026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.73ms)10122026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.15ms)10132026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.45ms)10142026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.83ms)10152026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010162026/10/01 08:28:13 OK 20251218171726_add_pins.sql (3.59ms)10172026/10/01 08:28:13 OK 3_commit_push.sql (1.44ms)10182026/10/01 08:28:13 goose: up to current file version: 310192026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4ms)10202026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.73ms)10212026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.26ms)10222026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)10232026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.86ms)10242026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.68ms)10252026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.86ms)10262026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (6.19ms)10272026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.16ms)10282026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (6.59ms)10292026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (3.39ms)10302026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010312026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.77ms)10322026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.88ms)10332026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010342026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.14ms)10352026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.65ms)10362026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)10372026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.34ms)10382026/10/01 08:28:13 OK 3_commit_push.sql (1.81ms)10392026/10/01 08:28:13 goose: up to current file version: 310402026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.64ms)10412026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010422026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.65ms)10432026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.32ms)10442026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.89ms)10452026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010462026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.26ms)10472026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.78ms)10482026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010492026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.24ms)10502026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.24ms)10512026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010522026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.01ms)10532026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.14ms)10542026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.24ms)10552026/10/01 08:28:13 OK 3_commit_push.sql (1.81ms)10562026/10/01 08:28:13 goose: up to current file version: 310572026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.49ms)10582026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)10592026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.99ms)10602026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3ms)10612026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.14ms)10622026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.51ms)10632026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.37ms)10642026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.39ms)10652026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.66ms)10662026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010672026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.96ms)10682026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.96ms)10692026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.85ms)10702026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.05ms)10712026/10/01 08:28:13 OK 3_commit_push.sql (1.28ms)10722026/10/01 08:28:13 goose: up to current file version: 310732026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.34ms)10742026/10/01 08:28:13 OK 3_commit_push.sql (1.11ms)10752026/10/01 08:28:13 goose: up to current file version: 310762026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.86ms)10772026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.49ms)10782026/10/01 08:28:13 OK 3_commit_push.sql (1.96ms)10792026/10/01 08:28:13 goose: up to current file version: 310802026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.18ms)10812026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010822026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.02ms)10832026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.78ms)10842026/10/01 08:28:13 OK 3_commit_push.sql (1.81ms)10852026/10/01 08:28:13 goose: up to current file version: 310862026/10/01 08:28:13 OK 3_commit_push.sql (1.53ms)10872026/10/01 08:28:13 goose: up to current file version: 310882026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.67ms)10892026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200001090--- PASS: TestMetricsInventory (0.49s)10912026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.29ms)1092=== CONT TestReadProxyHead10932026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000010942026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (3.31ms)10952026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.98ms)10962026/10/01 08:28:13 OK 3_commit_push.sql (2.17ms)10972026/10/01 08:28:13 goose: up to current file version: 310982026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.9ms)10992026/10/01 08:28:13 OK 3_commit_push.sql (1.64ms)11002026/10/01 08:28:13 goose: up to current file version: 311012026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.11ms)11022026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.84ms)11032026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.87ms)11042026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (11.75ms)11052026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000011062026/10/01 08:28:13 OK 3_commit_push.sql (10.37ms)11072026/10/01 08:28:13 goose: up to current file version: 311082026/10/01 08:28:13 OK 2_object_stats_trigger.sql (11.29ms)11092026/10/01 08:28:13 OK 2_object_stats_trigger.sql (11.39ms)11102026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.25ms)11112026/10/01 08:28:13 OK 3_commit_push.sql (1.56ms)11122026/10/01 08:28:13 goose: up to current file version: 311132026/10/01 08:28:13 OK 3_commit_push.sql (2.13ms)11142026/10/01 08:28:13 goose: up to current file version: 311152026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.34ms)11162026/10/01 08:28:13 OK 3_commit_push.sql (1.65ms)11172026/10/01 08:28:13 goose: up to current file version: 31118--- PASS: TestReadRedirectUsesPublicS3URL (0.52s)1119=== CONT TestReadProxyInvalidPath1120--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.47s)1121=== CONT TestReadProxy40411222026-10-01 08:28:13.549 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3611232026-10-01 08:28:13.549 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11242026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures11252026/10/01 08:28:13 OK 20241026095416_initial_model.sql (9.74ms)11262026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)11272026/10/01 08:28:13 OK 20251218171726_add_pins.sql (2.92ms)11282026-10-01 08:28:13.572 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611292026-10-01 08:28:13.572 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11302026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)11312026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.39ms)11322026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.25ms)11332026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.13ms)11342026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000011352026/10/01 08:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.35ms)11372026/10/01 08:28:13 OK 20241026095416_initial_model.sql (8.83ms)11382026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.8ms)11392026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)11402026/10/01 08:28:13 OK 3_commit_push.sql (1.57ms)11412026/10/01 08:28:13 goose: up to current file version: 311422026/10/01 08:28:13 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst11432026/10/01 08:28:13 OK 20251218171726_add_pins.sql (3.35ms)1144--- PASS: TestCompleteMultipartUnregistered (0.58s)1145=== CONT TestReadProxyNarStreaming11462026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)11472026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.56ms)11482026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (1.97ms)11492026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.1ms)11502026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000011512026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.49ms)11522026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.81ms)11532026/10/01 08:28:13 OK 3_commit_push.sql (1.39ms)11542026/10/01 08:28:13 goose: up to current file version: 311552026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures11562026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures11572026-10-01 08:28:13.645 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3611582026-10-01 08:28:13.645 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11592026-10-01 08:28:13.646 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611602026-10-01 08:28:13.646 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026-10-01 08:28:13.654 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3611622026-10-01 08:28:13.654 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11632026/10/01 08:28:13 OK 20241026095416_initial_model.sql (10.07ms)11642026/10/01 08:28:13 OK 20241026095416_initial_model.sql (9.12ms)11652026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)11662026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)11672026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.2ms)11682026/10/01 08:28:13 OK 20251218171726_add_pins.sql (5.85ms)11692026/10/01 08:28:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11702026/10/01 08:28:13 OK 20241026095416_initial_model.sql (9.08ms)11712026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)11722026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)11732026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)11742026/10/01 08:28:13 OK 20260905000000_add_claims.sql (2.91ms)11752026/10/01 08:28:13 INFO Aborted multipart uploads count=011762026/10/01 08:28:13 OK 20251218171726_add_pins.sql (4.21ms)11772026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.25ms)11782026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (1.75ms)11792026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures11802026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.09ms)11812026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (1.62ms)11822026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000011832026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)11842026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (1.41ms)11852026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000011862026/10/01 08:28:13 OK 1_commit_pending_closure.sql (1.85ms)11872026/10/01 08:28:13 OK 2_object_stats_trigger.sql (704.38µs)11882026/10/01 08:28:13 OK 20260905000000_add_claims.sql (2.58ms)11892026/10/01 08:28:13 OK 3_commit_push.sql (761.5µs)11902026/10/01 08:28:13 goose: up to current file version: 311912026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.07ms)11922026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.07ms)11932026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.12ms)11942026/10/01 08:28:13 OK 3_commit_push.sql (978.04µs)11952026/10/01 08:28:13 goose: up to current file version: 311962026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (1.49ms)11972026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000011982026/10/01 08:28:13 OK 1_commit_pending_closure.sql (1.99ms)11992026/10/01 08:28:13 INFO Received cleanup request method=DELETE path=/api/pending_closures12002026/10/01 08:28:13 OK 2_object_stats_trigger.sql (951.59µs)12012026-10-01 08:28:13.689 UTC [685] ERROR: relation "goose_db_version" does not exist at character 3612022026-10-01 08:28:13.689 UTC [685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12032026/10/01 08:28:13 OK 3_commit_push.sql (745.44µs)12042026/10/01 08:28:13 goose: up to current file version: 312052026/10/01 08:28:13 INFO Aborted multipart uploads count=112062026/10/01 08:28:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12072026-10-01 08:28:13.694 UTC [651] ERROR: Closure does not exist: id=112082026-10-01 08:28:13.694 UTC [651] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12092026-10-01 08:28:13.694 UTC [651] STATEMENT: -- name: CommitPendingClosure :exec1210 SELECT commit_pending_closure($1::bigint)1211 1212--- PASS: TestService_cleanupPendingClosuresHandler (0.68s)1213=== CONT TestGCSweepSkipsPendingObjects12142026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures12152026/10/01 08:28:13 OK 20241026095416_initial_model.sql (7.44ms)12162026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)12172026/10/01 08:28:13 OK 20251218171726_add_pins.sql (2.36ms)12182026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)12192026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.03ms)12212026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.22ms)12222026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.04ms)12232026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000012242026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.73ms)12252026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.65ms)12262026/10/01 08:28:13 OK 3_commit_push.sql (1.38ms)12272026/10/01 08:28:13 goose: up to current file version: 312282026/10/01 08:28:13 INFO Received push request method=POST path=/api/pushes12292026/10/01 08:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12302026/10/01 08:28:13 INFO Received push request method=POST path=/api/pushes12312026/10/01 08:28:13 INFO Received complete push request method=POST path=/api/pushes/1/complete12322026/10/01 08:28:13 INFO Received push request method=POST path=/api/pushes12332026/10/01 08:28:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12342026/10/01 08:28:13 INFO Signed narinfos id=1 count=11235--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.76s)1236=== CONT TestClientWithDependencies12372026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures12382026-10-01 08:28:13.781 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3612392026-10-01 08:28:13.781 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/10/01 08:28:13 OK 20241026095416_initial_model.sql (9.16ms)12412026/10/01 08:28:13 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12422026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures1243=== RUN TestPush_RejectsBadRequests/root_not_in_objects1244=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1245=== RUN TestPush_RejectsBadRequests/no_roots1246=== PAUSE TestPush_RejectsBadRequests/no_roots1247=== RUN TestPush_RejectsBadRequests/no_objects1248=== PAUSE TestPush_RejectsBadRequests/no_objects1249=== RUN TestPush_RejectsBadRequests/bad_root12502026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2ms)1251=== PAUSE TestPush_RejectsBadRequests/bad_root1252=== CONT TestNARDeduplicationMetadataUploadBug1253--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.79s)1254=== CONT TestDeduplicatedObjectsRecordedAsPending12552026/10/01 08:28:13 OK 20251218171726_add_pins.sql (2.97ms)12562026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (3.71ms)12572026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.45ms)12582026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.7ms)12592026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.81ms)12602026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000012612026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.17ms)12622026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.39ms)12632026/10/01 08:28:13 OK 3_commit_push.sql (1.55ms)12642026/10/01 08:28:13 goose: up to current file version: 312652026/10/01 08:28:13 INFO Aborted multipart uploads count=012662026/10/01 08:28:13 WARN Force mode enabled - objects will be deleted immediately without grace period12672026/10/01 08:28:13 INFO Received push request method=POST path=/api/pushes12682026/10/01 08:28:13 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=012692026/10/01 08:28:13 INFO Vacuumed table table=pending_closures12702026/10/01 08:28:13 INFO Vacuumed table table=pending_objects12712026/10/01 08:28:13 INFO Received push request method=POST path=/api/pushes12722026-10-01 08:28:13.866 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3612732026-10-01 08:28:13.866 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12742026/10/01 08:28:13 INFO Vacuumed table table=multipart_uploads12752026/10/01 08:28:13 INFO Received complete push request method=POST path=/api/pushes/1/complete12762026/10/01 08:28:13 INFO Vacuumed table table=closures12772026/10/01 08:28:13 INFO Vacuumed table table=objects12782026/10/01 08:28:13 INFO Received complete push request method=POST path=/api/pushes/2/complete1279--- PASS: TestPush_CompleteCommitsEveryRoot (0.87s)1280=== CONT TestCreatePendingClosureRejectsOversizedNAR12812026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures1282--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1283=== CONT TestPushDedupSurvivesConcurrentGC12842026/10/01 08:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12852026/10/01 08:28:13 OK 20241026095416_initial_model.sql (9.84ms)12862026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)1287--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.82s)1288=== CONT TestCacheConfigHandlerMaxNarSize1289--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1290=== CONT TestGCMetrics12912026/10/01 08:28:13 OK 20251218171726_add_pins.sql (2.6ms)12922026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)1293--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.88s)1294=== CONT TestGenerateLandingPage12952026/10/01 08:28:13 OK 20260905000000_add_claims.sql (3.15ms)12962026-10-01 08:28:13.895 UTC [708] ERROR: relation "goose_db_version" does not exist at character 3612972026-10-01 08:28:13.895 UTC [708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1298--- PASS: TestGenerateLandingPage (0.00s)1299=== CONT TestGCBugBareHashReferences13002026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.81ms)13012026-10-01 08:28:13.900 UTC [728] ERROR: relation "goose_db_version" does not exist at character 3613022026-10-01 08:28:13.900 UTC [728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13032026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (3.73ms)13042026/10/01 08:28:13 goose: successfully migrated database to version: 202609231200001305--- PASS: TestReadRedirectKeepsNarinfoProxied (0.83s)1306=== CONT TestLeadEndsOnShutdown13072026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.46ms)13082026/10/01 08:28:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzRjZDliNjQtNGRlZC00MzViLWJmY2UtNTc1ZGY2YWVjN2E1LjdjNGI4ZWNiLWZmMWUtNGM4Mi04ZWM2LTRjNWYwODNkZDY0NngxNzkwODQzMjkzNDYyMzM5OTQz parts=1013092026/10/01 08:28:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13102026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.55ms)13112026/10/01 08:28:13 OK 20241026095416_initial_model.sql (8.3ms)13122026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)13132026/10/01 08:28:13 OK 3_commit_push.sql (3.75ms)13142026/10/01 08:28:13 goose: up to current file version: 313152026/10/01 08:28:13 INFO Completed upload id=113162026/10/01 08:28:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013172026/10/01 08:28:13 OK 20241026095416_initial_model.sql (8.42ms)13182026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures13192026/10/01 08:28:13 OK 20251218171726_add_pins.sql (3.03ms)13202026/10/01 08:28:13 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)13212026/10/01 08:28:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures13222026/10/01 08:28:13 OK 20251218171726_add_pins.sql (2.81ms)13232026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)13242026/10/01 08:28:13 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)13252026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.46ms)1326--- PASS: TestService_Rustfstest (0.91s)1327=== CONT TestService_readinessHandler13282026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.7ms)13292026/10/01 08:28:13 OK 20260905000000_add_claims.sql (4.63ms)13302026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (1.74ms)13312026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000013322026/10/01 08:28:13 INFO Aborted multipart uploads count=013332026/10/01 08:28:13 OK 20260920000000_drop_claims.sql (2.53ms)13342026/10/01 08:28:13 OK 1_commit_pending_closure.sql (2.29ms)13352026/10/01 08:28:13 OK 20260923120000_add_pushes.sql (2.53ms)13362026/10/01 08:28:13 goose: successfully migrated database to version: 2026092312000013372026/10/01 08:28:13 OK 2_object_stats_trigger.sql (2.68ms)13382026/10/01 08:28:13 OK 3_commit_push.sql (1.8ms)13392026/10/01 08:28:13 goose: up to current file version: 313402026/10/01 08:28:13 OK 1_commit_pending_closure.sql (3.78ms)13412026/10/01 08:28:13 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=013422026/10/01 08:28:13 OK 2_object_stats_trigger.sql (1.55ms)13432026/10/01 08:28:13 INFO Vacuumed table table=pending_closures13442026/10/01 08:28:13 OK 3_commit_push.sql (2.72ms)13452026/10/01 08:28:13 goose: up to current file version: 313462026/10/01 08:28:13 INFO Vacuumed table table=pending_objects13472026/10/01 08:28:13 INFO Received uploads request method=POST path=/api/pending_closures13482026/10/01 08:28:13 INFO Vacuumed table table=multipart_uploads13492026/10/01 08:28:13 INFO Vacuumed table table=closures13502026/10/01 08:28:13 INFO Vacuumed table table=objects13512026/10/01 08:28:13 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001352--- PASS: TestService_createPendingClosureHandler (0.96s)1353=== CONT TestLeadElectsOneAndHandsOver13542026/10/01 08:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13552026-10-01 08:28:13.989 UTC [738] ERROR: relation "goose_db_version" does not exist at character 3613562026-10-01 08:28:13.989 UTC [738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1357--- PASS: TestReadRedirectNar (0.92s)1358=== CONT TestService_healthCheckHandler13592026/10/01 08:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13602026/10/01 08:28:13 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzRjZDliNjQtNGRlZC00MzViLWJmY2UtNTc1ZGY2YWVjN2E1LmQ2NTNhMjE4LTc4NjQtNGQzOC05OTM2LTE4ODFlYTRhN2UwNngxNzkwODQzMjkzOTY4NDM4Njg513612026/10/01 08:28:14 OK 20241026095416_initial_model.sql (10.41ms)13622026/10/01 08:28:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzRjZDliNjQtNGRlZC00MzViLWJmY2UtNTc1ZGY2YWVjN2E1LjEzYTI1ZTY3LThmY2MtNGEwZi05YTczLTliMmJkMzQ5N2UzZXgxNzkwODQzMjkzNTY5OTQ3Njky parts=1013632026/10/01 08:28:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13642026-10-01 08:28:14.008 UTC [741] ERROR: relation "goose_db_version" does not exist at character 3613652026-10-01 08:28:14.008 UTC [741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13662026/10/01 08:28:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzRjZDliNjQtNGRlZC00MzViLWJmY2UtNTc1ZGY2YWVjN2E1LmQ2NTNhMjE4LTc4NjQtNGQzOC05OTM2LTE4ODFlYTRhN2UwNngxNzkwODQzMjkzOTY4NDM4Njg5 parts=11367--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.94s)1368=== CONT TestResolveDBConnectionString13692026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)1370=== RUN TestResolveDBConnectionString/flag_wins1371=== PAUSE TestResolveDBConnectionString/flag_wins1372=== RUN TestResolveDBConnectionString/file_when_flag_empty1373=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1374=== RUN TestResolveDBConnectionString/missing_file_is_an_error13752026-10-01 08:28:14.010 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3613762026-10-01 08:28:14.010 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1377=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1378=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1379=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1380=== RUN TestResolveDBConnectionString/nothing_configured1381=== PAUSE TestResolveDBConnectionString/nothing_configured1382=== CONT TestClientFallsBackToClosures13832026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.06ms)13842026/10/01 08:28:14 INFO Completed upload id=113852026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures13862026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)13872026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures13882026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.2ms)1389--- PASS: TestReadProxyRangeRequest (0.95s)1390=== CONT TestGracefulShutdownDrainsInflight13912026/10/01 08:28:14 INFO Starting HTTP server address=127.0.0.1:3543913922026/10/01 08:28:14 INFO Shutdown signal received, draining in-flight requests timeout=10s13932026-10-01 08:28:14.028 UTC [745] ERROR: relation "goose_db_version" does not exist at character 3613942026-10-01 08:28:14.028 UTC [745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13952026/10/01 08:28:14 OK 20241026095416_initial_model.sql (22.03ms)13962026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (17.51ms)13972026/10/01 08:28:14 OK 20241026095416_initial_model.sql (23.49ms)13982026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)13992026/10/01 08:28:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14002026/10/01 08:28:14 WARN Found objects in DB but missing from S3, will re-upload count=11401--- PASS: TestService_verifyS3Integrity (1.03s)1402=== CONT TestClientPushesUseOnePush1403--- PASS: TestReadProxyDisabled (0.89s)1404=== CONT TestGCTaskStore_Fail1405--- PASS: TestGCTaskStore_Fail (0.00s)1406=== CONT TestPinProtectsFromGC14072026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)14082026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (3.99ms)14092026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000014102026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.53ms)14112026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.92ms)14122026/10/01 08:28:14 OK 1_commit_pending_closure.sql (4.15ms)14132026-10-01 08:28:14.049 UTC [746] ERROR: relation "goose_db_version" does not exist at character 3614142026-10-01 08:28:14.049 UTC [746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)14162026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.92ms)14172026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.73ms)14182026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)14192026/10/01 08:28:14 OK 3_commit_push.sql (1.56ms)14202026/10/01 08:28:14 goose: up to current file version: 314212026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)14222026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.94ms)14232026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.25ms)14242026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.51ms)14252026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.89ms)14262026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.82ms)14272026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.53ms)14282026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000014292026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.67ms)14302026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000014312026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)14322026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.67ms)14332026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.33ms)14342026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.94ms)14352026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.83ms)14362026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.71ms)14372026/10/01 08:28:14 OK 3_commit_push.sql (1.9ms)14382026/10/01 08:28:14 goose: up to current file version: 314392026/10/01 08:28:14 OK 20241026095416_initial_model.sql (12.76ms)14402026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.43ms)14412026/10/01 08:28:14 OK 3_commit_push.sql (2.44ms)14422026/10/01 08:28:14 goose: up to current file version: 314432026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)14442026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.69ms)14452026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000014462026/10/01 08:28:14 OK 20251218171726_add_pins.sql (4.73ms)14472026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.82ms)1448--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.67s)1449=== CONT TestGCTaskStore_PhaseUpdates1450--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1451=== CONT TestClientSharedPathCommittedMidPush14522026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.95ms)14532026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)14542026/10/01 08:28:14 OK 3_commit_push.sql (2.3ms)14552026/10/01 08:28:14 goose: up to current file version: 314562026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.02ms)14572026-10-01 08:28:14.085 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3614582026-10-01 08:28:14.085 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14592026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.64ms)14602026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (3.35ms)14612026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000014622026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.46ms)1463--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1464=== CONT TestGCTaskStore_CompletedAllowsNewTask1465--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1466=== CONT TestOrphanedObjectsGCStressTest14672026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.79ms)14682026/10/01 08:28:14 OK 3_commit_push.sql (2.44ms)14692026/10/01 08:28:14 goose: up to current file version: 314702026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.77ms)14712026-10-01 08:28:14.102 UTC [754] ERROR: relation "goose_db_version" does not exist at character 3614722026-10-01 08:28:14.102 UTC [754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14732026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)14742026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.54ms)1475--- PASS: TestReadProxyConditionalGet (0.67s)1476=== CONT TestGCTaskStore_GetReturnsLatest1477--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1478=== CONT TestGCTaskStore_GetEmpty1479--- PASS: TestGCTaskStore_GetEmpty (0.00s)1480=== CONT TestGCTaskStore_ConflictDifferentParams1481--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1482=== CONT TestGCTaskStore_DeduplicateSameParams1483--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1484=== CONT TestGCTaskStore_StartNew1485--- PASS: TestGCTaskStore_StartNew (0.00s)1486=== CONT TestGetExistingObjectsLocksRows14872026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (14.62ms)14882026/10/01 08:28:14 OK 20241026095416_initial_model.sql (14.55ms)14892026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)14902026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.21ms)14912026-10-01 08:28:14.129 UTC [758] ERROR: relation "goose_db_version" does not exist at character 3614922026-10-01 08:28:14.129 UTC [758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14932026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.9ms)14942026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.47ms)14952026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)14962026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.69ms)14972026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000014982026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.19ms)14992026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.49ms)15002026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.28ms)15012026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.37ms)1502--- PASS: TestReadProxyInvalidPath (0.61s)1503=== CONT TestRegisterCompletedObjectNeedsPendingRow15042026/10/01 08:28:14 OK 3_commit_push.sql (1.73ms)15052026/10/01 08:28:14 goose: up to current file version: 315062026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.41ms)15072026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000015082026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.6ms)15092026/10/01 08:28:14 OK 20241026095416_initial_model.sql (11.42ms)15102026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.77ms)15112026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)15122026/10/01 08:28:14 OK 3_commit_push.sql (2.29ms)15132026/10/01 08:28:14 goose: up to current file version: 315142026/10/01 08:28:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15152026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.52ms)15162026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)15172026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.92ms)15182026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.78ms)15192026-10-01 08:28:14.167 UTC [762] ERROR: relation "goose_db_version" does not exist at character 3615202026-10-01 08:28:14.167 UTC [762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15212026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.32ms)15222026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000015232026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.33ms)15242026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.65ms)15252026/10/01 08:28:14 OK 3_commit_push.sql (1.9ms)15262026/10/01 08:28:14 goose: up to current file version: 315272026/10/01 08:28:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzRjZDliNjQtNGRlZC00MzViLWJmY2UtNTc1ZGY2YWVjN2E1LjFiZGYyNWVkLTU2YjQtNDRmYS04NmUwLTZiOGYzN2FiZmM1MHgxNzkwODQzMjkzNjM4Mjc4NDg4 parts=1215282026-10-01 08:28:14.179 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3615292026-10-01 08:28:14.179 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1530--- PASS: TestReadProxyHead (0.67s)1531=== CONT TestSweepSkipsRowsLockedByPush15322026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures15332026/10/01 08:28:14 OK 20241026095416_initial_model.sql (10.66ms)1534--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.17s)1535=== CONT TestFailedS3DeleteKeepsTombstone15362026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (10.89ms)15372026/10/01 08:28:14 OK 20241026095416_initial_model.sql (12.77ms)15382026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.7ms)15392026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)15402026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.38ms)1541--- PASS: TestReadProxy404 (0.66s)1542=== CONT TestForceGCDuringPushOffersSweptObject15432026-10-01 08:28:14.205 UTC [767] ERROR: relation "goose_db_version" does not exist at character 3615442026-10-01 08:28:14.205 UTC [767] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1545=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1546=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1547=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check15482026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)1549=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1550=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15512026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)15522026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.25ms)15532026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.92ms)15542026-10-01 08:28:14.213 UTC [769] ERROR: relation "goose_db_version" does not exist at character 3615552026-10-01 08:28:14.213 UTC [769] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15562026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.31ms)15572026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.62ms)15582026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.33ms)15592026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000015602026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.23ms)15612026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000015622026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.07ms)15632026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.23ms)15642026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.43ms)15652026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.25ms)15662026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)15672026/10/01 08:28:14 OK 3_commit_push.sql (2.21ms)15682026/10/01 08:28:14 goose: up to current file version: 315692026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.22ms)15702026/10/01 08:28:14 OK 3_commit_push.sql (2.03ms)15712026/10/01 08:28:14 goose: up to current file version: 315722026/10/01 08:28:14 OK 20251218171726_add_pins.sql (4.39ms)15732026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.24ms)15742026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)15752026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)15762026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.47ms)15772026-10-01 08:28:14.235 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3615782026-10-01 08:28:14.235 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15792026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.15ms)15802026/10/01 08:28:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15812026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.28ms)15822026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)1583--- PASS: TestReadProxyNarStreaming (0.65s)1584=== CONT TestGCSweepDeliversEachKeyOnce15852026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (3.21ms)15862026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000015872026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.44ms)15882026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.58ms)15892026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2ms)15902026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.75ms)15912026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.71ms)15922026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000015932026/10/01 08:28:14 OK 3_commit_push.sql (1.68ms)15942026/10/01 08:28:14 goose: up to current file version: 315952026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.23ms)15962026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.47ms)15972026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)15982026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.65ms)15992026/10/01 08:28:14 OK 3_commit_push.sql (1.64ms)16002026/10/01 08:28:14 goose: up to current file version: 316012026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.36ms)16022026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)16032026-10-01 08:28:14.261 UTC [775] ERROR: relation "goose_db_version" does not exist at character 3616042026-10-01 08:28:14.261 UTC [775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16052026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.11ms)16062026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures16072026/10/01 08:28:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzRjZDliNjQtNGRlZC00MzViLWJmY2UtNTc1ZGY2YWVjN2E1Ljc4YmI3MDIxLTk0ODUtNGJkYi05NTgyLWM2ZmRlNGI0YWQ2NHgxNzkwODQzMjkzNzA3MDM3MjA0 parts=1216082026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.13ms)1609--- PASS: TestRedundantMultipartUpload (1.25s)1610=== CONT TestTombstonedObjectOfferedWithoutWaiting16112026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.11ms)16122026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000016132026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.47ms)16142026/10/01 08:28:14 OK 2_object_stats_trigger.sql (10.45ms)16152026/10/01 08:28:14 OK 20241026095416_initial_model.sql (19.27ms)16162026/10/01 08:28:14 OK 3_commit_push.sql (3.91ms)16172026/10/01 08:28:14 goose: up to current file version: 316182026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)16192026/10/01 08:28:14 OK 20251218171726_add_pins.sql (4.24ms)16202026-10-01 08:28:14.297 UTC [778] ERROR: relation "goose_db_version" does not exist at character 3616212026-10-01 08:28:14.297 UTC [778] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (5.45ms)16232026/10/01 08:28:14 INFO Aborted multipart uploads count=016242026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.14ms)16252026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period16262026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.79ms)16272026/10/01 08:28:14 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=016282026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (3.47ms)16292026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000016302026/10/01 08:28:14 INFO Vacuumed table table=pending_closures16312026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.47ms)16322026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.5ms)16332026/10/01 08:28:14 INFO Vacuumed table table=pending_objects16342026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)16352026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.13ms)16362026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads16372026/10/01 08:28:14 INFO Vacuumed table table=closures16382026/10/01 08:28:14 OK 3_commit_push.sql (1.46ms)16392026/10/01 08:28:14 goose: up to current file version: 316402026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.4ms)16412026/10/01 08:28:14 INFO Vacuumed table table=objects16422026-10-01 08:28:14.321 UTC [781] ERROR: relation "goose_db_version" does not exist at character 3616432026-10-01 08:28:14.321 UTC [781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16442026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)16452026-10-01 08:28:14.321 UTC [782] ERROR: relation "goose_db_version" does not exist at character 3616462026-10-01 08:28:14.321 UTC [782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1647--- PASS: TestGCSweepSkipsPendingObjects (0.63s)1648=== CONT TestMultipartCleanup16492026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.48ms)16502026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.02ms)16512026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (3.28ms)16522026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000016532026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.62ms)16542026/10/01 08:28:14 OK 20241026095416_initial_model.sql (8.67ms)16552026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.41ms)16562026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.15ms)16572026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)16582026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)16592026/10/01 08:28:14 OK 3_commit_push.sql (1.81ms)16602026/10/01 08:28:14 goose: up to current file version: 316612026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.94ms)16622026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.35ms)16632026-10-01 08:28:14.343 UTC [803] ERROR: relation "goose_db_version" does not exist at character 3616642026-10-01 08:28:14.343 UTC [803] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16652026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)16662026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)16672026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.27ms)16682026/10/01 08:28:14 OK 20260905000000_add_claims.sql (2.72ms)16692026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.48ms)16702026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (1.8ms)16712026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (1.98ms)16722026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000016732026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.32ms)16742026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000016752026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures16762026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.09ms)16772026/10/01 08:28:14 OK 1_commit_pending_closure.sql (3.71ms)16782026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.64ms)16792026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.6ms)16802026/10/01 08:28:14 OK 3_commit_push.sql (1.05ms)16812026/10/01 08:28:14 goose: up to current file version: 316822026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.79ms)16832026/10/01 08:28:14 OK 3_commit_push.sql (816.52µs)16842026/10/01 08:28:14 goose: up to current file version: 316852026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)16862026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.51ms)1687--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.57s)1688=== CONT TestOrphanedObjectsGC16892026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (5ms)1690=== NAME TestNARDeduplicationMetadataUploadBug1691 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1789940812/001/store/ki61sws23nr49x29l4z3l7m5ll2pk6b4-file1.txt16922026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.44ms)16932026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.57ms)16942026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (1.5ms)16952026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000016962026-10-01 08:28:14.382 UTC [840] ERROR: relation "goose_db_version" does not exist at character 3616972026-10-01 08:28:14.382 UTC [840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16982026/10/01 08:28:14 OK 1_commit_pending_closure.sql (5.04ms)1699=== NAME TestClientWithDependencies1700 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies908665320/001/store/68f6fzcmgqajcgccdgj77ymzqmn6hskx-test-script17012026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.9ms)17022026/10/01 08:28:14 OK 3_commit_push.sql (701.83µs)17032026/10/01 08:28:14 goose: up to current file version: 317042026/10/01 08:28:14 OK 20241026095416_initial_model.sql (8.37ms)17052026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (8.98ms)17062026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures17072026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.98ms)17082026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)17092026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.1ms)17102026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.31ms)1711 client_integration_test.go:615: Found 1 dependencies (including self)17122026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (1.87ms)17132026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000017142026/10/01 08:28:14 OK 1_commit_pending_closure.sql (1.77ms)17152026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.01ms)17162026/10/01 08:28:14 OK 3_commit_push.sql (1.82ms)17172026/10/01 08:28:14 goose: up to current file version: 317182026-10-01 08:28:14.436 UTC [878] ERROR: relation "goose_db_version" does not exist at character 3617192026-10-01 08:28:14.436 UTC [878] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17202026/10/01 08:28:14 INFO Aborted multipart uploads count=017212026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period17222026/10/01 08:28:14 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=017232026/10/01 08:28:14 INFO Vacuumed table table=pending_closures17242026/10/01 08:28:14 INFO Vacuumed table table=pending_objects17252026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads17262026/10/01 08:28:14 INFO Vacuumed table table=closures17272026/10/01 08:28:14 INFO Vacuumed table table=objects17282026/10/01 08:28:14 OK 20241026095416_initial_model.sql (8.51ms)17292026/10/01 08:28:14 INFO lead: acquired remote=192.0.2.1:123417302026/10/01 08:28:14 INFO lead: released remote=192.0.2.1:12341731--- PASS: TestLeadEndsOnShutdown (0.55s)1732=== CONT TestObjectStatsTrigger17332026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)1734--- PASS: TestGCMetrics (0.57s)17352026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes1736=== CONT TestCacheConfigHandler1737=== RUN TestCacheConfigHandler/full_config,_no_issuer1738=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1739=== RUN TestCacheConfigHandler/no_cache_url_configured1740=== PAUSE TestCacheConfigHandler/no_cache_url_configured1741=== RUN TestCacheConfigHandler/no_signing_keys1742=== PAUSE TestCacheConfigHandler/no_signing_keys1743=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1744=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1745=== CONT TestReadProxyNarinfo17462026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.29ms)17472026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)17482026/10/01 08:28:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17492026/10/01 08:28:14 INFO Uploading ki61sws23nr49x29l4z3l7m5ll2pk6b4-file1.txt (160B)17502026/10/01 08:28:14 OK 20260905000000_add_claims.sql (2.23ms)17512026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.19ms)17522026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (1.6ms)17532026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000017542026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17552026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17562026/10/01 08:28:14 WARN Failed to register uploaded object key=ki61sws23nr49x29l4z3l7m5ll2pk6b4.ls error="server returned 404: 404 page not found\n"17572026/10/01 08:28:14 OK 1_commit_pending_closure.sql (1.93ms)17582026/10/01 08:28:14 INFO Signed narinfos id=1 count=117592026/10/01 08:28:14 INFO Uploading 1 narinfos17602026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.94ms)17612026-10-01 08:28:14.470 UTC [918] ERROR: relation "goose_db_version" does not exist at character 3617622026-10-01 08:28:14.470 UTC [918] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17632026/10/01 08:28:14 OK 3_commit_push.sql (1.92ms)17642026/10/01 08:28:14 goose: up to current file version: 317652026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/1/complete17662026/10/01 08:28:14 WARN Failed to register uploaded object key=ki61sws23nr49x29l4z3l7m5ll2pk6b4.narinfo error="server returned 404: 404 page not found\n"17672026/10/01 08:28:14 WARN readiness check failed error="closed pool"1768--- PASS: TestService_readinessHandler (0.55s)1769=== CONT TestClientMultipleUploads17702026/10/01 08:28:14 INFO Aborted multipart uploads count=017712026/10/01 08:28:14 OK 20241026095416_initial_model.sql (10.65ms)17722026/10/01 08:28:14 INFO Upload complete. (71ms)1773=== NAME TestNARDeduplicationMetadataUploadBug1774 metadata_upload_test.go:54: Retrieved narinfo from S3:1775 StorePath: /build/TestNARDeduplicationMetadataUploadBug1789940812/001/store/ki61sws23nr49x29l4z3l7m5ll2pk6b4-file1.txt1776 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1777 Compression: zstd1778 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1779 NarSize: 1601780 References: 1781 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17822026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)17832026/10/01 08:28:14 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=01784 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)17852026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes1786 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1787 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17882026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.79ms)17892026/10/01 08:28:14 INFO Vacuumed table table=pending_closures17902026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)17912026/10/01 08:28:14 INFO Vacuumed table table=pending_objects17922026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads17932026/10/01 08:28:14 INFO lead: acquired remote=192.0.2.1:123417942026/10/01 08:28:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17952026/10/01 08:28:14 INFO Uploading 68f6fzcmgqajcgccdgj77ymzqmn6hskx-test-script (136B)17962026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.54ms)17972026/10/01 08:28:14 INFO Vacuumed table table=closures17982026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.47ms)17992026/10/01 08:28:14 INFO Vacuumed table table=objects18002026/10/01 08:28:14 WARN Failed to register uploaded object key=log/isi6sca2yp7034lj21zvydvrm97pyv31-test-script.drv error="server returned 404: 404 page not found\n"18012026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18022026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.28ms)18032026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000018042026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18052026/10/01 08:28:14 WARN Failed to register uploaded object key=68f6fzcmgqajcgccdgj77ymzqmn6hskx.ls error="server returned 404: 404 page not found\n"18062026/10/01 08:28:14 INFO Signed narinfos id=1 count=118072026/10/01 08:28:14 INFO Uploading 1 narinfos18082026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.5ms)18092026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.92ms)18102026/10/01 08:28:14 INFO Aborted multipart uploads count=018112026/10/01 08:28:14 WARN Failed to register uploaded object key=68f6fzcmgqajcgccdgj77ymzqmn6hskx.narinfo error="server returned 404: 404 page not found\n"18122026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/1/complete18132026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period18142026/10/01 08:28:14 OK 3_commit_push.sql (1.63ms)18152026/10/01 08:28:14 goose: up to current file version: 318162026/10/01 08:28:14 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=018172026/10/01 08:28:14 INFO Vacuumed table table=pending_closures18182026/10/01 08:28:14 INFO Vacuumed table table=pending_objects18192026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads18202026/10/01 08:28:14 INFO Vacuumed table table=closures18212026/10/01 08:28:14 INFO Vacuumed table table=objects1822--- PASS: TestPushDedupSurvivesConcurrentGC (0.64s)1823=== CONT TestParseSingleRange18242026/10/01 08:28:14 INFO Upload complete. (69ms)1825=== RUN TestParseSingleRange/none1826=== PAUSE TestParseSingleRange/none1827=== RUN TestParseSingleRange/unknown_unit1828=== PAUSE TestParseSingleRange/unknown_unit1829=== RUN TestParseSingleRange/multi-range_ignored1830=== PAUSE TestParseSingleRange/multi-range_ignored1831=== RUN TestParseSingleRange/malformed_no_dash1832=== PAUSE TestParseSingleRange/malformed_no_dash1833=== RUN TestParseSingleRange/malformed_both_empty1834=== PAUSE TestParseSingleRange/malformed_both_empty1835=== RUN TestParseSingleRange/malformed_end_before_start1836=== PAUSE TestParseSingleRange/malformed_end_before_start1837=== RUN TestParseSingleRange/closed1838=== PAUSE TestParseSingleRange/closed1839=== RUN TestParseSingleRange/open-ended1840=== PAUSE TestParseSingleRange/open-ended1841=== RUN TestParseSingleRange/end_clamped_to_size1842=== PAUSE TestParseSingleRange/end_clamped_to_size1843=== RUN TestParseSingleRange/suffix1844=== PAUSE TestParseSingleRange/suffix1845=== RUN TestParseSingleRange/suffix_exceeds_size1846=== PAUSE TestParseSingleRange/suffix_exceeds_size1847=== RUN TestParseSingleRange/single_byte1848=== PAUSE TestParseSingleRange/single_byte1849=== RUN TestParseSingleRange/start_past_EOF1850=== PAUSE TestParseSingleRange/start_past_EOF1851=== RUN TestParseSingleRange/start_far_past_EOF1852=== PAUSE TestParseSingleRange/start_far_past_EOF1853=== CONT TestClientIntegration1854=== NAME TestNARDeduplicationMetadataUploadBug1855 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1789940812/001/store/mi748jxrax34rk24msqn43hsz8b45sra-file2.txt1856=== NAME TestClientWithDependencies1857 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies908665320/001/store) requires matching store prefix1858--- PASS: TestService_healthCheckHandler (0.54s)1859=== CONT TestCreatePin_ReservedPins1860--- PASS: TestClientWithDependencies (0.76s)1861=== CONT TestClientErrorHandling1862=== RUN TestClientErrorHandling/InvalidStorePath1863=== PAUSE TestClientErrorHandling/InvalidStorePath1864=== RUN TestClientErrorHandling/InvalidAuthToken1865=== PAUSE TestClientErrorHandling/InvalidAuthToken1866=== RUN TestClientErrorHandling/ServerNotAvailable1867=== PAUSE TestClientErrorHandling/ServerNotAvailable1868=== CONT TestClientCADerivations18692026/10/01 08:28:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33173/oidc18702026-10-01 08:28:14.552 UTC [962] ERROR: relation "goose_db_version" does not exist at character 3618712026-10-01 08:28:14.552 UTC [962] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18722026-10-01 08:28:14.552 UTC [963] ERROR: relation "goose_db_version" does not exist at character 3618732026-10-01 08:28:14.552 UTC [963] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18742026/10/01 08:28:14 OK 20241026095416_initial_model.sql (11.31ms)18752026/10/01 08:28:14 OK 20241026095416_initial_model.sql (11.27ms)18762026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)18772026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)18782026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.21ms)18792026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.92ms)18802026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)18812026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)18822026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.53ms)18832026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.34ms)18842026-10-01 08:28:14.587 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 3618852026-10-01 08:28:14.587 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18862026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.32ms)18872026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.29ms)18882026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.24ms)18892026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000018902026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.62ms)18912026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000018922026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.6ms)18932026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.37ms)18942026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.62ms)18952026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.74ms)18962026/10/01 08:28:14 OK 3_commit_push.sql (1.89ms)18972026/10/01 08:28:14 goose: up to current file version: 318982026/10/01 08:28:14 OK 3_commit_push.sql (2.17ms)18992026/10/01 08:28:14 goose: up to current file version: 319002026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes19012026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.7ms)19022026/10/01 08:28:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19032026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)19042026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.81ms)19052026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19062026/10/01 08:28:14 INFO Signed narinfos id=2 count=119072026/10/01 08:28:14 WARN Failed to register uploaded object key=mi748jxrax34rk24msqn43hsz8b45sra.ls error="server returned 404: 404 page not found\n"19082026/10/01 08:28:14 INFO Uploading 1 narinfos19092026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)19102026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/2/complete19112026/10/01 08:28:14 WARN Failed to register uploaded object key=mi748jxrax34rk24msqn43hsz8b45sra.narinfo error="server returned 404: 404 page not found\n"19122026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.56ms)19132026/10/01 08:28:14 INFO Upload complete. (54ms)1914=== NAME TestNARDeduplicationMetadataUploadBug1915 metadata_upload_test.go:76: Retrieved narinfo from S3:1916 StorePath: /build/TestNARDeduplicationMetadataUploadBug1789940812/001/store/mi748jxrax34rk24msqn43hsz8b45sra-file2.txt19172026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.7ms)1918 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1919 Compression: zstd1920 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1921 NarSize: 1601922 References: 1923 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19242026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.06ms)19252026/10/01 08:28:14 goose: successfully migrated database to version: 202609231200001926 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1927 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1928 {"version":1,"root":{"type":"regular","size":44}}19292026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.76ms)19302026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.08ms)19312026/10/01 08:28:14 OK 3_commit_push.sql (890µs)19322026/10/01 08:28:14 goose: up to current file version: 31933--- PASS: TestNARDeduplicationMetadataUploadBug (0.83s)1934=== CONT TestCacheStatsHandler19352026-10-01 08:28:14.631 UTC [1055] ERROR: relation "goose_db_version" does not exist at character 3619362026-10-01 08:28:14.631 UTC [1055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19372026-10-01 08:28:14.635 UTC [1058] ERROR: relation "goose_db_version" does not exist at character 3619382026-10-01 08:28:14.635 UTC [1058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1939--- PASS: TestGCBugBareHashReferences (0.74s)1940=== CONT TestServerTLSConfig1941=== RUN TestServerTLSConfig/no_client_CA1942=== PAUSE TestServerTLSConfig/no_client_CA1943=== RUN TestServerTLSConfig/missing_CA_file1944=== PAUSE TestServerTLSConfig/missing_CA_file1945=== RUN TestServerTLSConfig/not_a_PEM_file1946=== PAUSE TestServerTLSConfig/not_a_PEM_file1947=== CONT TestIsValidCachePath1948=== RUN TestIsValidCachePath/narinfo1949=== PAUSE TestIsValidCachePath/narinfo1950=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1951=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1952=== RUN TestIsValidCachePath/nar_zst1953=== PAUSE TestIsValidCachePath/nar_zst1954=== RUN TestIsValidCachePath/nar_xz1955=== PAUSE TestIsValidCachePath/nar_xz1956=== RUN TestIsValidCachePath/nar_bz21957=== PAUSE TestIsValidCachePath/nar_bz21958=== RUN TestIsValidCachePath/nar_uncompressed1959=== PAUSE TestIsValidCachePath/nar_uncompressed1960=== RUN TestIsValidCachePath/ls1961=== PAUSE TestIsValidCachePath/ls1962=== RUN TestIsValidCachePath/log1963=== PAUSE TestIsValidCachePath/log1964=== RUN TestIsValidCachePath/realisation1965=== PAUSE TestIsValidCachePath/realisation1966=== RUN TestIsValidCachePath/nix-cache-info1967=== PAUSE TestIsValidCachePath/nix-cache-info1968=== RUN TestIsValidCachePath/index.html1969=== PAUSE TestIsValidCachePath/index.html1970=== RUN TestIsValidCachePath/traversal_parent1971=== PAUSE TestIsValidCachePath/traversal_parent1972=== RUN TestIsValidCachePath/traversal_in_middle1973=== PAUSE TestIsValidCachePath/traversal_in_middle1974=== RUN TestIsValidCachePath/invalid_char_e1975=== PAUSE TestIsValidCachePath/invalid_char_e1976=== RUN TestIsValidCachePath/invalid_char_u1977=== PAUSE TestIsValidCachePath/invalid_char_u1978=== RUN TestIsValidCachePath/random_path1979=== PAUSE TestIsValidCachePath/random_path1980=== RUN TestIsValidCachePath/empty1981=== PAUSE TestIsValidCachePath/empty1982=== RUN TestIsValidCachePath/leading_slash1983=== PAUSE TestIsValidCachePath/leading_slash1984=== RUN TestIsValidCachePath/wrong_extension1985=== PAUSE TestIsValidCachePath/wrong_extension1986=== RUN TestIsValidCachePath/short_hash1987=== PAUSE TestIsValidCachePath/short_hash1988=== CONT TestProxyHeadersOnlyTrustedOnSocket19892026/10/01 08:28:14 OK 20241026095416_initial_model.sql (8.43ms)19902026/10/01 08:28:14 INFO lead: released remote=192.0.2.1:123419912026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.79ms)19922026-10-01 08:28:14.654 UTC [1080] ERROR: relation "goose_db_version" does not exist at character 3619932026-10-01 08:28:14.654 UTC [1080] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19942026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)19952026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)19962026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.77ms)19972026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.46ms)19982026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)19992026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)20002026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.14ms)2001=== NAME TestPinProtectsFromGC2002 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3308762446/001/store/ykv2ikav543jjpql1cmvyjjc0ngl7wj0-pinned-file.txt2003 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3308762446/001/store/6b3g0lqrz16nw3fnbpiqsb3sxl56x75p-unpinned-file.txt20042026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.26ms)20052026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.62ms)20062026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.19ms)20072026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.06ms)20082026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.41ms)20092026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000020102026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.13ms)20112026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000020122026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)20132026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.33ms)20142026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.22ms)20152026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.42ms)20162026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.17ms)20172026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.48ms)20182026/10/01 08:28:14 OK 3_commit_push.sql (1.19ms)20192026/10/01 08:28:14 goose: up to current file version: 320202026/10/01 08:28:14 OK 3_commit_push.sql (1.32ms)20212026/10/01 08:28:14 goose: up to current file version: 320222026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)20232026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.04ms)20242026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (1.96ms)20252026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.55ms)20262026/10/01 08:28:14 goose: successfully migrated database to version: 202609231200002027--- PASS: TestGetExistingObjectsLocksRows (0.57s)2028=== CONT TestService_AuthMiddleware_MTLSBoundSubjects20292026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.22ms)20302026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.2ms)20312026/10/01 08:28:14 OK 3_commit_push.sql (1.09ms)20322026/10/01 08:28:14 goose: up to current file version: 32033--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.56s)2034=== CONT TestService_AuthMiddleware_MTLSProxyHeader20352026/10/01 08:28:14 INFO lead: acquired remote=192.0.2.1:123420362026/10/01 08:28:14 INFO lead: released remote=192.0.2.1:12342037--- PASS: TestLeadElectsOneAndHandsOver (0.74s)2038=== CONT TestService_AuthMiddleware_OIDC20392026-10-01 08:28:14.727 UTC [1224] ERROR: relation "goose_db_version" does not exist at character 3620402026-10-01 08:28:14.727 UTC [1224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20412026/10/01 08:28:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33985/oidc20422026-10-01 08:28:14.744 UTC [1234] ERROR: relation "goose_db_version" does not exist at character 3620432026-10-01 08:28:14.744 UTC [1234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20442026/10/01 08:28:14 OK 20241026095416_initial_model.sql (8.01ms)20452026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures20462026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)20472026/10/01 08:28:14 INFO Aborted multipart uploads count=020482026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures20492026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.89ms)20502026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/10/01 08:28:14 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 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)20532026/10/01 08:28:14 INFO Vacuumed table table=pending_closures20542026/10/01 08:28:14 INFO Vacuumed table table=pending_objects20552026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads20562026/10/01 08:28:14 INFO Vacuumed table table=closures20572026/10/01 08:28:14 OK 20260905000000_add_claims.sql (2.68ms)20582026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures20592026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.43ms)20602026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.77ms)20612026/10/01 08:28:14 INFO Vacuumed table table=objects20622026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes20632026/10/01 08:28:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20642026/10/01 08:28:14 INFO Uploading c5zirih2zxfvwbrma93ay4a00kwyw8q0-shared-dep (136B)20652026/10/01 08:28:14 INFO Uploading 5q5i414l6faslfkxx8q2ld7d275wv27m-a (216B)20662026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.62ms)20672026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000020682026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)20692026/10/01 08:28:14 INFO Aborted multipart uploads count=020702026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20712026/10/01 08:28:14 WARN Failed to register uploaded object key=nwfvd9g4x3nnrll5l6f6dsx7ink02gxl.ls error="server returned 404: 404 page not found\n"20722026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period20732026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/1idmhra25c6w0hbvqqj9a151bf91dxjnmnd5714w975mmv6501ra.nar.zst error="server returned 404: 404 page not found\n"20742026/10/01 08:28:14 WARN Failed to register uploaded object key=c5zirih2zxfvwbrma93ay4a00kwyw8q0.ls error="server returned 404: 404 page not found\n"20752026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20762026/10/01 08:28:14 WARN Failed to register uploaded object key=5q5i414l6faslfkxx8q2ld7d275wv27m.ls error="server returned 404: 404 page not found\n"20772026/10/01 08:28:14 INFO Signed narinfos id=1 count=220782026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20792026/10/01 08:28:14 INFO Signed narinfos id=2 count=220802026/10/01 08:28:14 INFO Uploading 4 narinfos20812026/10/01 08:28:14 WARN Failed to register uploaded object key=5q5i414l6faslfkxx8q2ld7d275wv27m.narinfo error="server returned 404: 404 page not found\n"20822026/10/01 08:28:14 WARN Failed to register uploaded object key=c5zirih2zxfvwbrma93ay4a00kwyw8q0.narinfo error="server returned 404: 404 page not found\n"20832026/10/01 08:28:14 WARN Failed to register uploaded object key=nwfvd9g4x3nnrll5l6f6dsx7ink02gxl.narinfo error="server returned 404: 404 page not found\n"20842026/10/01 08:28:14 OK 1_commit_pending_closure.sql (11.65ms)20852026/10/01 08:28:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20862026/10/01 08:28:14 WARN Failed to register uploaded object key=c5zirih2zxfvwbrma93ay4a00kwyw8q0.narinfo error="server returned 404: 404 page not found\n"20872026/10/01 08:28:14 OK 20251218171726_add_pins.sql (15.2ms)20882026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures20892026/10/01 08:28:14 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=020902026/10/01 08:28:14 OK 2_object_stats_trigger.sql (4.5ms)20912026/10/01 08:28:14 INFO Vacuumed table table=pending_closures20922026/10/01 08:28:14 INFO Vacuumed table table=pending_objects20932026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads20942026/10/01 08:28:14 INFO Completed upload id=120952026/10/01 08:28:14 INFO Vacuumed table table=closures20962026/10/01 08:28:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20972026/10/01 08:28:14 OK 3_commit_push.sql (1.18ms)20982026/10/01 08:28:14 goose: up to current file version: 320992026/10/01 08:28:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21002026/10/01 08:28:14 INFO Uploading ykv2ikav543jjpql1cmvyjjc0ngl7wj0-pinned-file.txt (128B)21012026/10/01 08:28:14 INFO Completed upload id=221022026/10/01 08:28:14 INFO Upload complete. (75ms)21032026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)2104=== NAME TestClientFallsBackToClosures2105 client_pushes_test.go:112: Retrieved narinfo from S3:2106 StorePath: /build/TestClientFallsBackToClosures2303330426/001/store/c5zirih2zxfvwbrma93ay4a00kwyw8q0-shared-dep2107 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2108 Compression: zstd2109 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822110 NarSize: 1362111 References: 2112 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21132026/10/01 08:28:14 INFO Vacuumed table table=objects2114--- PASS: TestSweepSkipsRowsLockedByPush (0.60s)2115=== CONT TestService_ReadAuthMiddleware21162026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes21172026/10/01 08:28:14 WARN Failed to register uploaded object key=ykv2ikav543jjpql1cmvyjjc0ngl7wj0.ls error="server returned 404: 404 page not found\n"2118=== NAME TestClientFallsBackToClosures21192026/10/01 08:28:14 OK 20260905000000_add_claims.sql (2.95ms)2120 client_pushes_test.go:112: Retrieved narinfo from S3:21212026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2122 StorePath: /build/TestClientFallsBackToClosures2303330426/001/store/5q5i414l6faslfkxx8q2ld7d275wv27m-a2123 URL: nar/1idmhra25c6w0hbvqqj9a151bf91dxjnmnd5714w975mmv6501ra.nar.zst2124 Compression: zstd2125 NarHash: sha256:1idmhra25c6w0hbvqqj9a151bf91dxjnmnd5714w975mmv6501ra2126 NarSize: 2162127 References: /build/TestClientFallsBackToClosures2303330426/001/store/c5zirih2zxfvwbrma93ay4a00kwyw8q0-shared-dep2128 CA: text:sha256:1ry47g47im1vhggrp6dbmyakzq2yky8nqbbm4f131cyc1w7grs4w21292026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21302026/10/01 08:28:14 INFO Signed narinfos id=1 count=121312026/10/01 08:28:14 INFO Uploading 1 narinfos21322026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.05ms)2133 client_pushes_test.go:112: Retrieved narinfo from S3:2134 StorePath: /build/TestClientFallsBackToClosures2303330426/001/store/nwfvd9g4x3nnrll5l6f6dsx7ink02gxl-b2135 URL: nar/1idmhra25c6w0hbvqqj9a151bf91dxjnmnd5714w975mmv6501ra.nar.zst2136 Compression: zstd2137 NarHash: sha256:1idmhra25c6w0hbvqqj9a151bf91dxjnmnd5714w975mmv6501ra2138 NarSize: 2162139 References: /build/TestClientFallsBackToClosures2303330426/001/store/c5zirih2zxfvwbrma93ay4a00kwyw8q0-shared-dep2140 CA: text:sha256:1ry47g47im1vhggrp6dbmyakzq2yky8nqbbm4f131cyc1w7grs4w21412026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.31ms)21422026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000021432026/10/01 08:28:14 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)21442026/10/01 08:28:14 INFO Uploading yyg7vhhd2kg65hbv8lxp6bvl6yp3ycgp-shared-dep (136B)21452026/10/01 08:28:14 INFO Uploading 6mhscvv5639qmmx3hsc4r6yslz86bwm8-top (224B)21462026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/1/complete21472026-10-01 08:28:14.791 UTC [1320] ERROR: relation "goose_db_version" does not exist at character 3621482026-10-01 08:28:14.791 UTC [1320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21492026/10/01 08:28:14 WARN Failed to register uploaded object key=ykv2ikav543jjpql1cmvyjjc0ngl7wj0.narinfo error="server returned 404: 404 page not found\n"21502026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.1ms)21512026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.02ms)21522026/10/01 08:28:14 OK 3_commit_push.sql (1.2ms)21532026/10/01 08:28:14 goose: up to current file version: 321542026/10/01 08:28:14 WARN Failed to register uploaded object key=6mhscvv5639qmmx3hsc4r6yslz86bwm8.ls error="server returned 404: 404 page not found\n"21552026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21562026/10/01 08:28:14 WARN Failed to register uploaded object key=yyg7vhhd2kg65hbv8lxp6bvl6yp3ycgp.ls error="server returned 404: 404 page not found\n"21572026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21582026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/0irdxc1vr0fpfsyc9gfm4ni6ws6190nh5hvrsd4x7f0z635gffrj.nar.zst error="server returned 404: 404 page not found\n"21592026/10/01 08:28:14 INFO Signed narinfos id=1 count=221602026/10/01 08:28:14 INFO Uploading 2 narinfos2161--- PASS: TestClientFallsBackToClosures (0.79s)2162=== CONT TestService_ReadScope_PublicByDefault21632026/10/01 08:28:14 WARN Failed to register uploaded object key=6mhscvv5639qmmx3hsc4r6yslz86bwm8.narinfo error="server returned 404: 404 page not found\n"21642026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/1/complete21652026/10/01 08:28:14 WARN Failed to register uploaded object key=yyg7vhhd2kg65hbv8lxp6bvl6yp3ycgp.narinfo error="server returned 404: 404 page not found\n"21662026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes21672026/10/01 08:28:14 INFO Upload complete. (91ms)21682026/10/01 08:28:14 INFO Upload complete. (58ms)2169=== NAME TestClientSharedPathCommittedMidPush2170 client_integration_test.go:680: Retrieved narinfo from S3:2171 StorePath: /build/TestClientSharedPathCommittedMidPush2745066424/001/store/yyg7vhhd2kg65hbv8lxp6bvl6yp3ycgp-shared-dep2172 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2173 Compression: zstd2174 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822175 NarSize: 1362176 References: 2177 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21782026/10/01 08:28:14 OK 20241026095416_initial_model.sql (10.08ms)2179 client_integration_test.go:680: Retrieved narinfo from S3:2180 StorePath: /build/TestClientSharedPathCommittedMidPush2745066424/001/store/6mhscvv5639qmmx3hsc4r6yslz86bwm8-top2181 URL: nar/0irdxc1vr0fpfsyc9gfm4ni6ws6190nh5hvrsd4x7f0z635gffrj.nar.zst2182 Compression: zstd2183 NarHash: sha256:0irdxc1vr0fpfsyc9gfm4ni6ws6190nh5hvrsd4x7f0z635gffrj2184 NarSize: 2242185 References: /build/TestClientSharedPathCommittedMidPush2745066424/001/store/yyg7vhhd2kg65hbv8lxp6bvl6yp3ycgp-shared-dep2186 CA: text:sha256:1qjkid64s6r17h3vphpfis6wil5kzvi4ppsc5izmxkgd8hhgi15d21872026/10/01 08:28:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21882026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)21892026/10/01 08:28:14 INFO Uploading jyl4pghsqhbnkypi5klmpwl2h619526z-shared-dep (136B)21902026/10/01 08:28:14 INFO Uploading 1njzxk91522808997a5jgawp73nymjay-b (216B)21912026/10/01 08:28:14 WARN Failed to register uploaded object key=d2bkr5d0j6x91a00rv5rgmv9lraw0qvp.ls error="server returned 404: 404 page not found\n"21922026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures21932026/10/01 08:28:14 WARN Failed to register uploaded object key=1njzxk91522808997a5jgawp73nymjay.ls error="server returned 404: 404 page not found\n"21942026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21952026/10/01 08:28:14 WARN Failed to register uploaded object key=jyl4pghsqhbnkypi5klmpwl2h619526z.ls error="server returned 404: 404 page not found\n"21962026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21972026/10/01 08:28:14 OK 20251218171726_add_pins.sql (4.75ms)21982026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/0f6giw3ssfn4qrrgs508ypdzjsx3c2ymvxkxvjzlqjc88ps7ih3v.nar.zst error="server returned 404: 404 page not found\n"21992026/10/01 08:28:14 INFO Signed narinfos id=1 count=322002026/10/01 08:28:14 INFO Uploading 3 narinfos22012026-10-01 08:28:14.816 UTC [1344] ERROR: relation "goose_db_version" does not exist at character 3622022026-10-01 08:28:14.816 UTC [1344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2203--- PASS: TestClientSharedPathCommittedMidPush (0.74s)2204=== CONT TestService_RequireScope_OIDC22052026/10/01 08:28:14 WARN Failed to register uploaded object key=jyl4pghsqhbnkypi5klmpwl2h619526z.narinfo error="server returned 404: 404 page not found\n"22062026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)22072026/10/01 08:28:14 WARN Failed to register uploaded object key=d2bkr5d0j6x91a00rv5rgmv9lraw0qvp.narinfo error="server returned 404: 404 page not found\n"22082026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/1/complete22092026/10/01 08:28:14 WARN Failed to register uploaded object key=1njzxk91522808997a5jgawp73nymjay.narinfo error="server returned 404: 404 page not found\n"22102026/10/01 08:28:14 INFO Aborted multipart uploads count=022112026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.24ms)22122026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period2213--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.56s)2214=== CONT TestService_NativeMTLS22152026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.35ms)22162026/10/01 08:28:14 INFO Received uploads request method=POST path=/api/pending_closures22172026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.39ms)22182026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000022192026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.75ms)22202026/10/01 08:28:14 OK 20241026095416_initial_model.sql (10.16ms)22212026/10/01 08:28:14 INFO Upload complete. (80ms)2222=== NAME TestClientPushesUseOnePush2223 client_pushes_test.go:97: Retrieved narinfo from S3:2224 StorePath: /build/TestClientPushesUseOnePush3214635468/001/store/jyl4pghsqhbnkypi5klmpwl2h619526z-shared-dep2225 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2226 Compression: zstd2227 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822228 NarSize: 1362229 References: 2230 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22312026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.51ms)22322026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)22332026/10/01 08:28:14 OK 3_commit_push.sql (1.49ms)22342026/10/01 08:28:14 goose: up to current file version: 32235 client_pushes_test.go:97: Retrieved narinfo from S3:2236 StorePath: /build/TestClientPushesUseOnePush3214635468/001/store/d2bkr5d0j6x91a00rv5rgmv9lraw0qvp-a2237 URL: nar/0f6giw3ssfn4qrrgs508ypdzjsx3c2ymvxkxvjzlqjc88ps7ih3v.nar.zst2238 Compression: zstd2239 NarHash: sha256:0f6giw3ssfn4qrrgs508ypdzjsx3c2ymvxkxvjzlqjc88ps7ih3v2240 NarSize: 2162241 References: /build/TestClientPushesUseOnePush3214635468/001/store/jyl4pghsqhbnkypi5klmpwl2h619526z-shared-dep2242 CA: text:sha256:0fmn5sx5ja0sbb4nlz9dn50cmy1mvn4zvvkpiqb8jw3nfm6i4pir22432026/10/01 08:28:14 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=02244 client_pushes_test.go:97: Retrieved narinfo from S3:2245 StorePath: /build/TestClientPushesUseOnePush3214635468/001/store/1njzxk91522808997a5jgawp73nymjay-b2246 URL: nar/0f6giw3ssfn4qrrgs508ypdzjsx3c2ymvxkxvjzlqjc88ps7ih3v.nar.zst22472026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.44ms)2248 Compression: zstd2249 NarHash: sha256:0f6giw3ssfn4qrrgs508ypdzjsx3c2ymvxkxvjzlqjc88ps7ih3v2250 NarSize: 2162251 References: /build/TestClientPushesUseOnePush3214635468/001/store/jyl4pghsqhbnkypi5klmpwl2h619526z-shared-dep2252 CA: text:sha256:0fmn5sx5ja0sbb4nlz9dn50cmy1mvn4zvvkpiqb8jw3nfm6i4pir22532026/10/01 08:28:14 INFO Aborted multipart uploads count=022542026/10/01 08:28:14 INFO Vacuumed table table=pending_closures22552026/10/01 08:28:14 INFO Vacuumed table table=pending_objects22562026/10/01 08:28:14 INFO Vacuumed table table=multipart_uploads22572026/10/01 08:28:14 INFO Vacuumed table table=closures22582026-10-01 08:28:14.841 UTC [1361] ERROR: relation "goose_db_version" does not exist at character 3622592026-10-01 08:28:14.841 UTC [1361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22602026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period22612026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)22622026/10/01 08:28:14 INFO Vacuumed table table=objects2263--- PASS: TestGCSweepDeliversEachKeyOnce (0.60s)2264=== CONT TestIsValidUploadKey/narinfo2265=== CONT TestIsValidUploadKey/realisation_plus_in_output2266=== CONT TestIsValidUploadKey/unknown_type2267=== CONT TestIsValidUploadKey/empty_key2268=== CONT TestIsValidUploadKey/absolute2269=== CONT TestIsValidUploadKey/traversal_nar2270=== CONT TestIsValidUploadKey/traversal2271=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2272=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2273=== CONT TestIsValidUploadKey/nix-cache-info2274=== CONT TestIsValidUploadKey/build_log_home-manager_file2275=== CONT TestIsValidUploadKey/realisation2276=== CONT TestIsValidUploadKey/build_log_equals2277=== CONT TestIsValidUploadKey/build_log_question_mark2278=== CONT TestIsValidUploadKey/build_log_plus_in_name2279=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2280=== CONT TestIsValidUploadKey/nar_plain2281=== CONT TestIsValidUploadKey/build_log2282=== CONT TestIsValidUploadKey/nar_xz2283--- PASS: TestClientPushesUseOnePush (0.80s)2284=== CONT TestIsValidUploadKey/nar_zst22852026/10/01 08:28:14 OK 20260905000000_add_claims.sql (2.92ms)2286=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2287=== CONT TestIsValidUploadKey/listing22882026/10/01 08:28:14 INFO Received uploads request method=POST path=/2289=== CONT TestIsValidUploadKey/index.html2290--- PASS: TestIsValidUploadKey (0.06s)2291 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2292 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2293 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2294 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2295 --- PASS: TestIsValidUploadKey/absolute (0.00s)2296 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2297 --- PASS: TestIsValidUploadKey/traversal (0.00s)2298 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2299 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2300 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2301 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2302 --- PASS: TestIsValidUploadKey/realisation (0.00s)2303 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2304 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2305 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2306 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2307 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2308 --- PASS: TestIsValidUploadKey/build_log (0.00s)2309 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2310 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2311 --- PASS: TestIsValidUploadKey/listing (0.00s)2312 --- PASS: TestIsValidUploadKey/index.html (0.00s)2313=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2314=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23152026/10/01 08:28:14 INFO Received request for more parts method=POST path=/23162026/10/01 08:28:14 INFO Received complete multipart upload request method=POST path=/2317=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2318=== CONT TestProxyWriteTimeout/narinfo23192026/10/01 08:28:14 INFO Received uploads request method=POST path=/2320=== CONT TestProxyWriteTimeout/10_GiB_nar2321--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)2322 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2323 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2324 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2325 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2326=== CONT TestProxyWriteTimeout/1_GiB_nar2327=== CONT TestProxyWriteTimeout/unknown_size2328--- PASS: TestProxyWriteTimeout (0.06s)2329 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2330 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2331 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2332 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2333=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2334=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23352026/10/01 08:28:14 INFO Received request for more parts method=POST path=/23362026/10/01 08:28:14 INFO Received uploads request method=POST path=/23372026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.21ms)23382026/10/01 08:28:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."23392026/10/01 08:28:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."23402026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (1.87ms)23412026/10/01 08:28:14 goose: successfully migrated database to version: 202609231200002342--- PASS: TestFailedS3DeleteKeepsTombstone (0.67s)23432026/10/01 08:28:14 OK 1_commit_pending_closure.sql (1.84ms)2344=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23452026/10/01 08:28:14 INFO Received complete multipart upload request method=POST path=/23462026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.37ms)23472026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.79ms)23482026/10/01 08:28:14 OK 3_commit_push.sql (2.5ms)23492026/10/01 08:28:14 goose: up to current file version: 323502026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)23512026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.24ms)23522026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)23532026/10/01 08:28:14 OK 20260905000000_add_claims.sql (10.2ms)23542026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.57ms)2355=== CONT TestPush_RejectsBadRequests/root_not_in_objects23562026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes2357=== CONT TestPush_RejectsBadRequests/no_roots23582026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes2359=== CONT TestPush_RejectsBadRequests/bad_root23602026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes2361=== CONT TestPush_RejectsBadRequests/no_objects23622026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes23632026/10/01 08:28:14 INFO Received push request method=POST path=/api/pushes2364=== CONT TestResolveDBConnectionString/flag_wins2365=== CONT TestResolveDBConnectionString/missing_file_is_an_error2366--- PASS: TestPush_RejectsBadRequests (0.73s)2367 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2368 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2369 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2370 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2371=== CONT TestResolveDBConnectionString/file_when_flag_empty2372=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2373=== CONT TestResolveDBConnectionString/nothing_configured2374=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2375--- PASS: TestResolveDBConnectionString (0.00s)2376 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2377 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2378 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2379 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2380 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)23812026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (3.06ms)23822026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000023832026/10/01 08:28:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23842026/10/01 08:28:14 INFO Uploading 6b3g0lqrz16nw3fnbpiqsb3sxl56x75p-unpinned-file.txt (128B)23852026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.49ms)23862026/10/01 08:28:14 OK 2_object_stats_trigger.sql (1.56ms)23872026/10/01 08:28:14 OK 3_commit_push.sql (1.27ms)23882026/10/01 08:28:14 goose: up to current file version: 323892026-10-01 08:28:14.890 UTC [1386] ERROR: relation "goose_db_version" does not exist at character 3623902026-10-01 08:28:14.890 UTC [1386] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2391--- PASS: TestReadProxyNarinfo (0.44s)2392=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check23932026/10/01 08:28:14 WARN Failed to register uploaded object key=6b3g0lqrz16nw3fnbpiqsb3sxl56x75p.ls error="server returned 404: 404 page not found\n"23942026/10/01 08:28:14 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23952026/10/01 08:28:14 INFO Signed narinfos id=2 count=123962026/10/01 08:28:14 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"23972026/10/01 08:28:14 INFO Uploading 1 narinfos23982026/10/01 08:28:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33995/oidc23992026-10-01 08:28:14.897 UTC [1388] ERROR: relation "goose_db_version" does not exist at character 3624002026-10-01 08:28:14.897 UTC [1388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24012026/10/01 08:28:14 INFO Received complete push request method=POST path=/api/pushes/2/complete2402--- PASS: TestObjectStatsTrigger (0.45s)24032026/10/01 08:28:14 WARN Failed to register uploaded object key=6b3g0lqrz16nw3fnbpiqsb3sxl56x75p.narinfo error="server returned 404: 404 page not found\n"2404=== CONT TestCacheConfigHandler/full_config,_no_issuer2405=== CONT TestCacheConfigHandler/no_signing_keys2406=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2407=== CONT TestCacheConfigHandler/no_cache_url_configured2408--- PASS: TestCacheConfigHandler (0.00s)2409 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2410 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2411 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2412 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2413=== CONT TestParseSingleRange/none2414=== CONT TestParseSingleRange/open-ended2415=== CONT TestParseSingleRange/start_far_past_EOF2416=== CONT TestParseSingleRange/start_past_EOF2417=== CONT TestParseSingleRange/single_byte2418=== CONT TestParseSingleRange/suffix_exceeds_size2419=== CONT TestParseSingleRange/suffix2420=== CONT TestParseSingleRange/malformed_both_empty2421=== CONT TestParseSingleRange/end_clamped_to_size2422=== CONT TestParseSingleRange/closed2423=== CONT TestParseSingleRange/malformed_end_before_start2424=== CONT TestParseSingleRange/multi-range_ignored2425=== CONT TestParseSingleRange/malformed_no_dash2426=== CONT TestParseSingleRange/unknown_unit2427--- PASS: TestParseSingleRange (0.00s)2428 --- PASS: TestParseSingleRange/none (0.00s)2429 --- PASS: TestParseSingleRange/open-ended (0.00s)2430 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2431 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2432 --- PASS: TestParseSingleRange/single_byte (0.00s)2433 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2434 --- PASS: TestParseSingleRange/suffix (0.00s)2435 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2436 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2437 --- PASS: TestParseSingleRange/closed (0.00s)2438 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2439 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2440 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2441 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2442=== CONT TestClientErrorHandling/InvalidStorePath24432026/10/01 08:28:14 INFO Upload complete. (59ms)24442026/10/01 08:28:14 OK 20241026095416_initial_model.sql (8.39ms)24452026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)24462026/10/01 08:28:14 OK 20251218171726_add_pins.sql (2.76ms)24472026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)24482026/10/01 08:28:14 OK 20241026095416_initial_model.sql (10.78ms)24492026/10/01 08:28:14 OK 20260905000000_add_claims.sql (4.12ms)24502026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)24512026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.46ms)24522026/10/01 08:28:14 OK 20251218171726_add_pins.sql (3.75ms)24532026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.54ms)24542026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000024552026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.39ms)24562026-10-01 08:28:14.925 UTC [1397] ERROR: relation "goose_db_version" does not exist at character 3624572026-10-01 08:28:14.925 UTC [1397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24582026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)24592026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.11ms)24602026/10/01 08:28:14 OK 3_commit_push.sql (1.63ms)24612026/10/01 08:28:14 goose: up to current file version: 324622026/10/01 08:28:14 OK 20260905000000_add_claims.sql (3.58ms)24632026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (3.04ms)24642026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.43ms)24652026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000024662026/10/01 08:28:14 OK 1_commit_pending_closure.sql (2.88ms)24672026/10/01 08:28:14 INFO Received create pin request method=POST path=/api/pins/myapp24682026/10/01 08:28:14 OK 2_object_stats_trigger.sql (2.1ms)24692026/10/01 08:28:14 OK 20241026095416_initial_model.sql (9.62ms)24702026/10/01 08:28:14 OK 3_commit_push.sql (1.79ms)24712026/10/01 08:28:14 goose: up to current file version: 324722026/10/01 08:28:14 INFO Received cleanup request method=DELETE path=/api/pending_closures24732026/10/01 08:28:14 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)2474=== CONT TestClientErrorHandling/ServerNotAvailable24752026/10/01 08:28:14 INFO Aborted multipart uploads count=124762026/10/01 08:28:14 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3308762446/001/store/ykv2ikav543jjpql1cmvyjjc0ngl7wj0-pinned-file.txt narinfo_key=ykv2ikav543jjpql1cmvyjjc0ngl7wj0.narinfo24772026/10/01 08:28:14 OK 20251218171726_add_pins.sql (4.41ms)24782026/10/01 08:28:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures24792026/10/01 08:28:14 INFO Garbage collection started2480--- PASS: TestMultipartCleanup (0.63s)2481=== CONT TestClientErrorHandling/InvalidAuthToken24822026/10/01 08:28:14 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)24832026/10/01 08:28:14 OK 20260905000000_add_claims.sql (2.84ms)2484=== NAME TestClientMultipleUploads2485 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2853883821/001/store/jn5101bgd8xn51f3l0a88bk86c3ksal2-test-file-0.txt24862026/10/01 08:28:14 OK 20260920000000_drop_claims.sql (2.44ms)24872026/10/01 08:28:14 OK 20260923120000_add_pushes.sql (2.43ms)24882026/10/01 08:28:14 goose: successfully migrated database to version: 2026092312000024892026/10/01 08:28:14 INFO Aborted multipart uploads count=024902026/10/01 08:28:14 WARN Force mode enabled - objects will be deleted immediately without grace period24912026/10/01 08:28:14 OK 1_commit_pending_closure.sql (12.6ms)24922026/10/01 08:28:14 OK 2_object_stats_trigger.sql (4.02ms)24932026/10/01 08:28:14 OK 3_commit_push.sql (2.56ms)24942026/10/01 08:28:14 goose: up to current file version: 324952026/10/01 08:28:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24962026/10/01 08:28:14 WARN Refused reserved pin name=worker-x86_64-linux24972026/10/01 08:28:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24982026/10/01 08:28:14 INFO Received create pin request method=POST path=/api/pins/my-app24992026/10/01 08:28:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux25002026-10-01 08:28:14.988 UTC [1475] ERROR: relation "goose_db_version" does not exist at character 3625012026-10-01 08:28:14.988 UTC [1475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2502--- PASS: TestCreatePin_ReservedPins (0.46s)2503=== CONT TestServerTLSConfig/no_client_CA2504=== CONT TestServerTLSConfig/not_a_PEM_file2505=== CONT TestServerTLSConfig/missing_CA_file2506--- PASS: TestServerTLSConfig (0.00s)2507 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2508 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2509 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2510=== CONT TestIsValidCachePath/narinfo2511=== CONT TestIsValidCachePath/index.html2512=== CONT TestIsValidCachePath/short_hash2513=== CONT TestIsValidCachePath/wrong_extension2514=== CONT TestIsValidCachePath/leading_slash2515=== CONT TestIsValidCachePath/invalid_char_e2516=== CONT TestIsValidCachePath/traversal_in_middle2517=== CONT TestIsValidCachePath/traversal_parent2518=== CONT TestIsValidCachePath/invalid_char_u2519=== CONT TestIsValidCachePath/empty2520=== CONT TestIsValidCachePath/random_path2521=== CONT TestIsValidCachePath/nar_uncompressed2522=== CONT TestIsValidCachePath/realisation2523=== CONT TestIsValidCachePath/log2524=== NAME TestClientMultipleUploads2525 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2853883821/001/store/525j5yj6r3cfizkr179wwdyyrgfqnm8b-test-file-1.txt2526=== CONT TestIsValidCachePath/nix-cache-info2527=== CONT TestIsValidCachePath/ls2528=== CONT TestIsValidCachePath/nar_xz2529=== CONT TestIsValidCachePath/nar_zst2530=== CONT TestIsValidCachePath/nar_bz22531=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2532--- PASS: TestIsValidCachePath (0.00s)2533 --- PASS: TestIsValidCachePath/narinfo (0.00s)2534 --- PASS: TestIsValidCachePath/index.html (0.00s)2535 --- PASS: TestIsValidCachePath/short_hash (0.00s)2536 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2537 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2538 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2539 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2540 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2541 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2542 --- PASS: TestIsValidCachePath/empty (0.00s)2543 --- PASS: TestIsValidCachePath/random_path (0.00s)2544 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2545 --- PASS: TestIsValidCachePath/realisation (0.00s)2546 --- PASS: TestIsValidCachePath/log (0.00s)2547 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2548 --- PASS: TestIsValidCachePath/ls (0.00s)2549 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2550 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2551 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2552 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)25532026/10/01 08:28:14 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=02554--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.79s)25552026/10/01 08:28:14 INFO Vacuumed table table=pending_closures25562026-10-01 08:28:14.998 UTC [1505] ERROR: relation "goose_db_version" does not exist at character 3625572026-10-01 08:28:14.998 UTC [1505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25582026/10/01 08:28:15 INFO Vacuumed table table=pending_objects25592026/10/01 08:28:15 INFO Vacuumed table table=multipart_uploads2560=== NAME TestClientIntegration2561 client_integration_test.go:286: Created store path: /build/TestClientIntegration89333995/002/store/z9ryh17kigaifs58psad2zwa6i38jgcc-test-file.txt25622026-10-01 08:28:15.003 UTC [1507] ERROR: relation "goose_db_version" does not exist at character 3625632026-10-01 08:28:15.003 UTC [1507] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25642026/10/01 08:28:15 INFO Vacuumed table table=closures25652026/10/01 08:28:15 OK 20241026095416_initial_model.sql (9.62ms)25662026-10-01 08:28:15.006 UTC [1508] ERROR: relation "goose_db_version" does not exist at character 3625672026-10-01 08:28:15.006 UTC [1508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25682026/10/01 08:28:15 INFO Vacuumed table table=objects25692026/10/01 08:28:15 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)25702026/10/01 08:28:15 OK 20251218171726_add_pins.sql (2.75ms)25712026/10/01 08:28:15 OK 20241026095416_initial_model.sql (9.21ms)25722026/10/01 08:28:15 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)25732026/10/01 08:28:15 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)25742026/10/01 08:28:15 OK 20241026095416_initial_model.sql (7.97ms)25752026/10/01 08:28:15 OK 20260905000000_add_claims.sql (3.08ms)25762026/10/01 08:28:15 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)25772026/10/01 08:28:15 OK 20251218171726_add_pins.sql (3.15ms)25782026/10/01 08:28:15 OK 20260920000000_drop_claims.sql (1.9ms)25792026/10/01 08:28:15 OK 20251218171726_add_pins.sql (2.7ms)25802026/10/01 08:28:15 OK 20241026095416_initial_model.sql (9.52ms)25812026/10/01 08:28:15 OK 20260923120000_add_pushes.sql (2.27ms)25822026/10/01 08:28:15 goose: successfully migrated database to version: 2026092312000025832026/10/01 08:28:15 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)25842026/10/01 08:28:15 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)25852026/10/01 08:28:15 OK 20260628120000_add_object_size_and_stats.sql (3.37ms)25862026/10/01 08:28:15 OK 1_commit_pending_closure.sql (2.43ms)2587--- PASS: TestCacheStatsHandler (0.40s)25882026/10/01 08:28:15 OK 20260905000000_add_claims.sql (3.07ms)25892026/10/01 08:28:15 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/present25902026/10/01 08:28:15 OK 2_object_stats_trigger.sql (1.62ms)2591=== NAME TestClientMultipleUploads2592 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2853883821/001/store/nvcigbxzcw8lhcbnz5banjb0y9banixj-test-file-2.txt25932026/10/01 08:28:15 OK 20251218171726_add_pins.sql (3.8ms)25942026/10/01 08:28:15 OK 20260905000000_add_claims.sql (3.08ms)25952026/10/01 08:28:15 OK 3_commit_push.sql (1.19ms)25962026/10/01 08:28:15 goose: up to current file version: 325972026/10/01 08:28:15 OK 20260920000000_drop_claims.sql (2.46ms)25982026/10/01 08:28:15 OK 20260920000000_drop_claims.sql (3.17ms)25992026/10/01 08:28:15 OK 20260923120000_add_pushes.sql (2.67ms)26002026/10/01 08:28:15 goose: successfully migrated database to version: 202609231200002601=== NAME TestClientCADerivations26022026/10/01 08:28:15 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)2603 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3381599379/001/store/jyc5cyr5w9gjml8m1gy75bn36qvn9sc7-ca-test26042026/10/01 08:28:15 OK 20260923120000_add_pushes.sql (1.54ms)26052026/10/01 08:28:15 goose: successfully migrated database to version: 2026092312000026062026/10/01 08:28:15 OK 1_commit_pending_closure.sql (2.56ms)26072026/10/01 08:28:15 OK 1_commit_pending_closure.sql (1.93ms)26082026/10/01 08:28:15 OK 20260905000000_add_claims.sql (3.11ms)26092026/10/01 08:28:15 OK 2_object_stats_trigger.sql (1.15ms)26102026/10/01 08:28:15 OK 2_object_stats_trigger.sql (1.12ms)26112026/10/01 08:28:15 OK 3_commit_push.sql (1.71ms)26122026/10/01 08:28:15 goose: up to current file version: 326132026/10/01 08:28:15 OK 20260920000000_drop_claims.sql (2.65ms)26142026/10/01 08:28:15 INFO Starting HTTP server address=127.0.0.1:3521926152026/10/01 08:28:15 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket12997657/001/proxy.sock26162026/10/01 08:28:15 OK 3_commit_push.sql (1.68ms)26172026/10/01 08:28:15 goose: up to current file version: 326182026/10/01 08:28:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"26192026/10/01 08:28:15 INFO Shutdown signal received, draining in-flight requests timeout=10s2620--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.40s)26212026/10/01 08:28:15 OK 20260923120000_add_pushes.sql (2.43ms)26222026/10/01 08:28:15 goose: successfully migrated database to version: 2026092312000026232026/10/01 08:28:15 OK 1_commit_pending_closure.sql (1.88ms)26242026/10/01 08:28:15 OK 2_object_stats_trigger.sql (849.34µs)26252026/10/01 08:28:15 OK 3_commit_push.sql (677.8µs)26262026/10/01 08:28:15 goose: up to current file version: 326272026-10-01 08:28:15.051 UTC [1580] ERROR: relation "goose_db_version" does not exist at character 3626282026-10-01 08:28:15.051 UTC [1580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26292026/10/01 08:28:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26302026/10/01 08:28:15 WARN mTLS auth: bound subjects configured but subject DN unavailable26312026/10/01 08:28:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2632--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)26332026/10/01 08:28:15 OK 20241026095416_initial_model.sql (7.69ms)26342026/10/01 08:28:15 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)2635=== NAME TestClientCADerivations2636 client_ca_test.go:139: Found 1 dependencies (including self)26372026/10/01 08:28:15 OK 20251218171726_add_pins.sql (2.54ms)26382026/10/01 08:28:15 INFO Received push request method=POST path=/api/pushes26392026/10/01 08:28:15 OK 20260628120000_add_object_size_and_stats.sql (2.88ms)26402026/10/01 08:28:15 OK 20260905000000_add_claims.sql (3.1ms)26412026/10/01 08:28:15 OK 20260920000000_drop_claims.sql (1.62ms)26422026/10/01 08:28:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26432026/10/01 08:28:15 INFO Uploading z9ryh17kigaifs58psad2zwa6i38jgcc-test-file.txt (152B)26442026/10/01 08:28:15 OK 20260923120000_add_pushes.sql (1.2ms)26452026/10/01 08:28:15 goose: successfully migrated database to version: 2026092312000026462026/10/01 08:28:15 OK 1_commit_pending_closure.sql (1.56ms)26472026/10/01 08:28:15 OK 2_object_stats_trigger.sql (963.95µs)26482026/10/01 08:28:15 OK 3_commit_push.sql (774.47µs)26492026/10/01 08:28:15 goose: up to current file version: 326502026/10/01 08:28:15 WARN Failed to register uploaded object key=z9ryh17kigaifs58psad2zwa6i38jgcc.ls error="server returned 404: 404 page not found\n"26512026/10/01 08:28:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26522026/10/01 08:28:15 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"26532026/10/01 08:28:15 INFO Signed narinfos id=1 count=126542026/10/01 08:28:15 INFO Uploading 1 narinfos2655--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.39s)26562026/10/01 08:28:15 INFO Received complete push request method=POST path=/api/pushes/1/complete26572026/10/01 08:28:15 WARN Failed to register uploaded object key=z9ryh17kigaifs58psad2zwa6i38jgcc.narinfo error="server returned 404: 404 page not found\n"26582026/10/01 08:28:15 INFO Upload complete. (56ms)26592026/10/01 08:28:15 INFO Received push request method=POST path=/api/pushes26602026/10/01 08:28:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)26612026/10/01 08:28:15 INFO Uploading nvcigbxzcw8lhcbnz5banjb0y9banixj-test-file-2.txt (160B)26622026/10/01 08:28:15 INFO Uploading jn5101bgd8xn51f3l0a88bk86c3ksal2-test-file-0.txt (160B)26632026/10/01 08:28:15 INFO Uploading 525j5yj6r3cfizkr179wwdyyrgfqnm8b-test-file-1.txt (160B)2664=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2665=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2666=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2667=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2668=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2669=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2670=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2671=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2672=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2673=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected26742026/10/01 08:28:15 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2675=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2676=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26772026/10/01 08:28:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"26782026/10/01 08:28:15 WARN Failed to register uploaded object key=nvcigbxzcw8lhcbnz5banjb0y9banixj.ls error="server returned 404: 404 page not found\n"26792026/10/01 08:28:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"26802026/10/01 08:28:15 WARN Authentication failed token_preview=eyJhbGciOi...eIsfJltiDw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]26812026/10/01 08:28:15 WARN Failed to register uploaded object key=jn5101bgd8xn51f3l0a88bk86c3ksal2.ls error="server returned 404: 404 page not found\n"26822026/10/01 08:28:15 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"2683--- PASS: TestService_AuthMiddleware_OIDC (0.40s)2684 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2685 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2686 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2687 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)26882026/10/01 08:28:15 WARN Failed to register uploaded object key=525j5yj6r3cfizkr179wwdyyrgfqnm8b.ls error="server returned 404: 404 page not found\n"26892026/10/01 08:28:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26902026/10/01 08:28:15 INFO Signed narinfos id=1 count=326912026/10/01 08:28:15 INFO Uploading 3 narinfos26922026/10/01 08:28:15 WARN Failed to register uploaded object key=jn5101bgd8xn51f3l0a88bk86c3ksal2.narinfo error="server returned 404: 404 page not found\n"26932026/10/01 08:28:15 INFO Received complete push request method=POST path=/api/pushes/1/complete26942026/10/01 08:28:15 WARN Failed to register uploaded object key=525j5yj6r3cfizkr179wwdyyrgfqnm8b.narinfo error="server returned 404: 404 page not found\n"26952026/10/01 08:28:15 WARN Failed to register uploaded object key=nvcigbxzcw8lhcbnz5banjb0y9banixj.narinfo error="server returned 404: 404 page not found\n"26962026/10/01 08:28:15 INFO Upload complete. (62ms)2697=== NAME TestClientMultipleUploads2698 client_integration_test.go:369: Uploaded 3 paths in 97.602869ms26992026/10/01 08:28:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.21524ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2700--- PASS: TestClientMultipleUploads (0.66s)2701--- PASS: TestService_ReadAuthMiddleware (0.35s)27022026/10/01 08:28:15 INFO All 1 paths already cached2703=== NAME TestClientIntegration2704 client_integration_test.go:312: Retrieved narinfo from S3:2705 StorePath: /build/TestClientIntegration89333995/002/store/z9ryh17kigaifs58psad2zwa6i38jgcc-test-file.txt2706 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2707 Compression: zstd2708 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12709 NarSize: 1522710 References: 2711 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12712 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2713 client_integration_test.go:313: Decompressed .ls content (64 bytes):2714 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2715 client_integration_test.go:316: Testing garbage collection...2716=== NAME TestOrphanedObjectsGC2717 orphaned_objects_gc_test.go:290: GC Test Summary:2718 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2719 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2720 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2721 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2722 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2723--- PASS: TestOrphanedObjectsGC (0.79s)2724--- PASS: TestService_ReadScope_PublicByDefault (0.36s)27252026/10/01 08:28:15 INFO Received push request method=POST path=/api/pushes27262026/10/01 08:28:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures27272026/10/01 08:28:15 INFO Garbage collection started27282026/10/01 08:28:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27292026/10/01 08:28:15 INFO Uploading jyc5cyr5w9gjml8m1gy75bn36qvn9sc7-ca-test (144B)27302026/10/01 08:28:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"27312026/10/01 08:28:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2732--- PASS: TestService_NativeMTLS (0.36s)27332026/10/01 08:28:15 WARN Failed to register uploaded object key=log/cdy9mkrajr0ksgz2srhc0xqbxna5x7pb-ca-test.drv error="server returned 404: 404 page not found\n"27342026/10/01 08:28:15 INFO Aborted multipart uploads count=027352026/10/01 08:28:15 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"27362026/10/01 08:28:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27372026/10/01 08:28:15 WARN Failed to register uploaded object key=jyc5cyr5w9gjml8m1gy75bn36qvn9sc7.ls error="server returned 404: 404 page not found\n"27382026/10/01 08:28:15 INFO Signed narinfos id=1 count=127392026/10/01 08:28:15 INFO Uploading 1 narinfos27402026/10/01 08:28:15 WARN Force mode enabled - objects will be deleted immediately without grace period27412026/10/01 08:28:15 INFO Received complete push request method=POST path=/api/pushes/1/complete27422026/10/01 08:28:15 WARN Failed to register uploaded object key=jyc5cyr5w9gjml8m1gy75bn36qvn9sc7.narinfo error="server returned 404: 404 page not found\n"27432026/10/01 08:28:15 INFO Upload complete. (98ms)27442026/10/01 08:28:15 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=02745=== NAME TestClientCADerivations2746 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3381599379/001/store/jyc5cyr5w9gjml8m1gy75bn36qvn9sc7-ca-test2747 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2748 Compression: zstd2749 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2750 NarSize: 1442751 References: 2752 Deriver: /build/TestClientCADerivations3381599379/001/store/cdy9mkrajr0ksgz2srhc0xqbxna5x7pb-ca-test.drv2753 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2754 client_ca_test.go:185: Checking for realisation files in S3...27552026/10/01 08:28:15 INFO Vacuumed table table=pending_closures2756 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2757 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache27582026/10/01 08:28:15 INFO Vacuumed table table=pending_objects27592026/10/01 08:28:15 INFO Vacuumed table table=multipart_uploads27602026/10/01 08:28:15 INFO Vacuumed table table=closures27612026/10/01 08:28:15 INFO Vacuumed table table=objects27622026/10/01 08:28:15 INFO Received uploads request method=POST path=/api/pending_closures27632026/10/01 08:28:15 INFO Aborted multipart uploads count=027642026/10/01 08:28:15 WARN Force mode enabled - objects will be deleted immediately without grace period27652026/10/01 08:28:15 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=027662026/10/01 08:28:15 INFO Vacuumed table table=pending_closures27672026/10/01 08:28:15 INFO Vacuumed table table=pending_objects27682026/10/01 08:28:15 INFO Vacuumed table table=multipart_uploads27692026/10/01 08:28:15 INFO Vacuumed table table=closures27702026/10/01 08:28:15 INFO Vacuumed table table=objects2771=== RUN TestService_RequireScope_OIDC/builder_may_write2772=== PAUSE TestService_RequireScope_OIDC/builder_may_write2773=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2774=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2775=== RUN TestService_RequireScope_OIDC/ops_may_admin2776=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2777=== RUN TestService_RequireScope_OIDC/ops_may_not_write2778=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2779=== RUN TestService_RequireScope_OIDC/reader_may_not_write2780=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2781=== RUN TestService_RequireScope_OIDC/static_token_may_admin2782=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2783=== RUN TestService_RequireScope_OIDC/static_token_may_write2784=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2785=== RUN TestService_RequireScope_OIDC/reader_may_read2786=== PAUSE TestService_RequireScope_OIDC/reader_may_read2787=== RUN TestService_RequireScope_OIDC/writer_implies_read2788=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2789=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2790=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2791=== CONT TestService_RequireScope_OIDC/builder_may_write2792=== CONT TestService_RequireScope_OIDC/reader_may_read2793=== CONT TestService_RequireScope_OIDC/static_token_may_admin2794=== CONT TestService_RequireScope_OIDC/static_token_may_write2795=== CONT TestService_RequireScope_OIDC/writer_implies_read2796=== CONT TestService_RequireScope_OIDC/ops_may_not_write2797=== CONT TestService_RequireScope_OIDC/reader_may_not_write2798=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2799=== CONT TestService_RequireScope_OIDC/ops_may_admin2800=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2801--- PASS: TestService_RequireScope_OIDC (0.42s)2802 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2803 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2804 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2805 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2806 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2807 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2808 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2809 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2810 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2811 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)28122026/10/01 08:28:15 INFO Received uploads request method=POST path=/api/pending_closures28132026/10/01 08:28:15 INFO Aborted multipart uploads count=028142026/10/01 08:28:15 WARN Force mode enabled - objects will be deleted immediately without grace period28152026/10/01 08:28:15 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=028162026/10/01 08:28:15 INFO Vacuumed table table=pending_closures28172026/10/01 08:28:15 INFO Vacuumed table table=pending_objects28182026/10/01 08:28:15 INFO Vacuumed table table=multipart_uploads28192026/10/01 08:28:15 INFO Vacuumed table table=closures28202026/10/01 08:28:15 INFO Vacuumed table table=objects2821--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2822 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.37s)2823 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.39s)28242026/10/01 08:28:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.708888ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2825=== NAME TestClientCADerivations2826 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2827 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2828 error: binary cache 's3://bucket61?endpoint=http://localhost:40615®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3381599379/001/store'2829 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12830--- PASS: TestClientCADerivations (0.80s)28312026/10/01 08:28:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28322026/10/01 08:28:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2833--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2834 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2835 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)2836 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.85s)28372026/10/01 08:28:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.688559ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2838=== NAME TestOrphanedObjectsGCStressTest2839 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2840 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion28412026/10/01 08:28:16 WARN Rate limiter enabled after throttle name=s3-test rate=528422026/10/01 08:28:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2843=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2844 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102845 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002846--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.20s)2847=== NAME TestOrphanedObjectsGCStressTest2848 orphaned_objects_gc_test.go:509: Stress test completed successfully:2849 orphaned_objects_gc_test.go:510: - Active objects preserved: 202850 orphaned_objects_gc_test.go:511: - Objects deleted: 2102851 orphaned_objects_gc_test.go:512: - Total GC'd: 2102852--- PASS: TestOrphanedObjectsGCStressTest (2.24s)28532026/10/01 08:28:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.721558687s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28542026/10/01 08:28:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02855=== NAME TestPinProtectsFromGC2856 client_integration_test.go:794: Pin successfully protected closure from garbage collection2857--- PASS: TestPinProtectsFromGC (2.92s)28582026/10/01 08:28:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02859=== NAME TestClientIntegration2860 client_integration_test.go:323: Objects in database after GC:2861 client_integration_test.go:323: Successfully deleted all objects with GC --force2862--- PASS: TestClientIntegration (2.66s)28632026/10/01 08:28:18 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28642026/10/01 08:28:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.378183ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28652026/10/01 08:28:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.420018ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28662026/10/01 08:28:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=823.796443ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28672026/10/01 08:28:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.586715983s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28682026/10/01 08:28:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"28692026/10/01 08:28:21 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28702026/10/01 08:28:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.49765ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28712026/10/01 08:28:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.802817ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28722026/10/01 08:28:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.302116ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28732026/10/01 08:28:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.483421024s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28742026/10/01 08:28:24 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28752026/10/01 08:28:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.22115ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28762026/10/01 08:28:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.903726ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28772026/10/01 08:28:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=755.731887ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28782026/10/01 08:28:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.48939496s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2879--- PASS: TestClientErrorHandling (0.00s)2880 --- PASS: TestClientErrorHandling/InvalidStorePath (0.40s)2881 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.46s)2882 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.28s)2883PASS28842026-10-01 08:28:27.510 UTC [127] LOG: received smart shutdown request28852026-10-01 08:28:27.514 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 128862026-10-01 08:28:27.521 UTC [132] LOG: shutting down28872026-10-01 08:28:27.522 UTC [132] LOG: checkpoint starting: shutdown immediate28882026-10-01 08:28:29.119 UTC [132] LOG: checkpoint complete: wrote 10428 buffers (63.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 21 recycled; write=0.258 s, sync=1.292 s, total=1.598 s; sync files=25607, longest=0.002 s, average=0.001 s; distance=348430 kB, estimate=348430 kB; lsn=0/16BA97D0, redo lsn=0/16BA97D028892026-10-01 08:28:29.192 UTC [127] LOG: database system is shut down2890Running OIDC tests...2891=== RUN TestAudienceForIssuer2892=== PAUSE TestAudienceForIssuer2893=== RUN TestGlobMatch2894=== PAUSE TestGlobMatch2895=== RUN TestValidateToken_ValidToken2896=== PAUSE TestValidateToken_ValidToken2897=== RUN TestValidateToken_WrongAudience2898=== PAUSE TestValidateToken_WrongAudience2899=== RUN TestValidateToken_Expired2900=== PAUSE TestValidateToken_Expired2901=== RUN TestValidateToken_BoundClaimsMismatch2902=== PAUSE TestValidateToken_BoundClaimsMismatch2903=== RUN TestValidateToken_BoundSubjectMismatch2904=== PAUSE TestValidateToken_BoundSubjectMismatch2905=== RUN TestValidateToken_MultipleProviders2906=== PAUSE TestValidateToken_MultipleProviders2907=== RUN TestValidateToken_NoMatchingProvider2908=== PAUSE TestValidateToken_NoMatchingProvider2909=== RUN TestValidateToken_KubernetesServiceAccount2910=== PAUSE TestValidateToken_KubernetesServiceAccount2911=== RUN TestNewValidator_KubernetesRequiresCA2912=== PAUSE TestNewValidator_KubernetesRequiresCA2913=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2914=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2915=== RUN TestPins_ReservedForMatchingRule2916=== PAUSE TestPins_ReservedForMatchingRule2917=== RUN TestPins_TopLevelShorthand2918=== PAUSE TestPins_TopLevelShorthand2919=== RUN TestPins_ConfigValidation2920=== PAUSE TestPins_ConfigValidation2921=== RUN TestScopes_LegacyProviderDefaultsToWrite2922=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2923=== RUN TestScopes_Rules2924=== PAUSE TestScopes_Rules2925=== RUN TestScopes_ConfigValidation2926=== PAUSE TestScopes_ConfigValidation2927=== CONT TestAudienceForIssuer2928=== CONT TestValidateToken_KubernetesServiceAccount2929=== CONT TestValidateToken_BoundClaimsMismatch2930=== CONT TestValidateToken_NoMatchingProvider2931--- PASS: TestAudienceForIssuer (0.00s)2932=== CONT TestValidateToken_MultipleProviders2933=== CONT TestValidateToken_ValidToken2934=== CONT TestValidateToken_BoundSubjectMismatch2935=== CONT TestGlobMatch2936=== RUN TestGlobMatch/foo_foo2937=== PAUSE TestGlobMatch/foo_foo2938=== RUN TestGlobMatch/foo_bar2939=== PAUSE TestGlobMatch/foo_bar2940=== CONT TestPins_ConfigValidation2941=== CONT TestScopes_ConfigValidation2942=== CONT TestScopes_Rules2943=== CONT TestValidateToken_Expired2944=== CONT TestScopes_LegacyProviderDefaultsToWrite2945--- PASS: TestPins_ConfigValidation (0.00s)2946=== CONT TestPins_ReservedForMatchingRule2947=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2948=== CONT TestPins_TopLevelShorthand2949=== CONT TestNewValidator_KubernetesRequiresCA2950=== CONT TestValidateToken_WrongAudience2951=== RUN TestGlobMatch/*_2952=== PAUSE TestGlobMatch/*_2953=== RUN TestGlobMatch/*_anything2954=== PAUSE TestGlobMatch/*_anything2955=== RUN TestGlobMatch/foo*_foo2956=== PAUSE TestGlobMatch/foo*_foo2957=== RUN TestGlobMatch/foo*_foobar2958=== PAUSE TestGlobMatch/foo*_foobar2959=== RUN TestGlobMatch/foo*_bar2960=== PAUSE TestGlobMatch/foo*_bar2961=== RUN TestGlobMatch/*bar_bar2962=== PAUSE TestGlobMatch/*bar_bar2963=== RUN TestGlobMatch/*bar_foobar2964=== PAUSE TestGlobMatch/*bar_foobar2965=== RUN TestGlobMatch/*bar_foo2966=== PAUSE TestGlobMatch/*bar_foo2967=== RUN TestGlobMatch/foo*bar_foobar2968=== PAUSE TestGlobMatch/foo*bar_foobar2969=== RUN TestGlobMatch/foo*bar_foo123bar2970=== PAUSE TestGlobMatch/foo*bar_foo123bar2971=== RUN TestGlobMatch/foo*bar_foobarbaz2972=== PAUSE TestGlobMatch/foo*bar_foobarbaz2973=== RUN TestGlobMatch/*/*_foo/bar2974=== PAUSE TestGlobMatch/*/*_foo/bar2975=== RUN TestGlobMatch/*/*_foo2976=== PAUSE TestGlobMatch/*/*_foo2977=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2978=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2979=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02980=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02981=== RUN TestGlobMatch/refs/*/main_refs/heads/main2982=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2983=== RUN TestGlobMatch/fo?_foo2984=== PAUSE TestGlobMatch/fo?_foo2985=== RUN TestGlobMatch/fo?_fo2986=== PAUSE TestGlobMatch/fo?_fo2987--- PASS: TestScopes_ConfigValidation (0.00s)2988=== RUN TestGlobMatch/fo?_fooo2989=== PAUSE TestGlobMatch/fo?_fooo2990=== RUN TestGlobMatch/?oo_foo2991=== PAUSE TestGlobMatch/?oo_foo2992=== RUN TestGlobMatch/?oo_boo2993=== PAUSE TestGlobMatch/?oo_boo2994=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2995=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2996=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2997=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2998=== CONT TestGlobMatch/foo_foo2999=== CONT TestGlobMatch/foo*bar_foobar3000=== CONT TestGlobMatch/*_anything3001=== CONT TestGlobMatch/foo_bar3002=== CONT TestGlobMatch/*/*_foo/bar3003=== CONT TestGlobMatch/fo?_fooo3004=== CONT TestGlobMatch/*bar_foobar3005=== CONT TestGlobMatch/foo*_bar3006=== CONT TestGlobMatch/foo*bar_foobarbaz3007=== CONT TestGlobMatch/foo*_foobar3008=== CONT TestGlobMatch/fo?_fo3009=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03010=== CONT TestGlobMatch/*/*_foo3011=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3012=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3013=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3014=== CONT TestGlobMatch/?oo_boo3015=== CONT TestGlobMatch/*bar_foo3016=== CONT TestGlobMatch/?oo_foo3017=== CONT TestGlobMatch/*bar_bar3018=== CONT TestGlobMatch/foo*_foo3019=== CONT TestGlobMatch/foo*bar_foo123bar3020=== CONT TestGlobMatch/*_3021=== CONT TestGlobMatch/refs/*/main_refs/heads/main3022=== CONT TestGlobMatch/fo?_foo3023--- PASS: TestGlobMatch (0.01s)3024 --- PASS: TestGlobMatch/foo_foo (0.00s)3025 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3026 --- PASS: TestGlobMatch/*_anything (0.00s)3027 --- PASS: TestGlobMatch/foo_bar (0.00s)3028 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3029 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3030 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3031 --- PASS: TestGlobMatch/foo*_bar (0.00s)3032 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3033 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3034 --- PASS: TestGlobMatch/fo?_fo (0.00s)3035 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3036 --- PASS: TestGlobMatch/*/*_foo (0.00s)3037 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3038 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3039 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3040 --- PASS: TestGlobMatch/?oo_boo (0.00s)3041 --- PASS: TestGlobMatch/*bar_foo (0.00s)3042 --- PASS: TestGlobMatch/?oo_foo (0.00s)3043 --- PASS: TestGlobMatch/*bar_bar (0.00s)3044 --- PASS: TestGlobMatch/foo*_foo (0.00s)3045 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3046 --- PASS: TestGlobMatch/*_ (0.00s)3047 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3048 --- PASS: TestGlobMatch/fo?_foo (0.00s)30492026/10/01 08:28:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33447/oidc3050--- PASS: TestValidateToken_Expired (0.02s)30512026/10/01 08:28:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:379993052--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)30532026/10/01 08:28:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42975/oidc3054--- PASS: TestScopes_Rules (0.04s)30552026/10/01 08:28:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42925/oidc3056--- PASS: TestPins_ReservedForMatchingRule (0.07s)30572026/10/01 08:28:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42165/oidc3058--- PASS: TestValidateToken_WrongAudience (0.08s)30592026/10/01 08:28:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35723/oidc3060--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)30612026/10/01 08:28:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39637/oidc3062--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)30632026/10/01 08:28:31 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12330642026/10/01 08:28:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34065/oidc3065--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)3066--- PASS: TestPins_TopLevelShorthand (0.10s)30672026/10/01 08:28:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42941/oidc3068--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)30692026/10/01 08:28:31 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38077/oidc3070--- PASS: TestValidateToken_NoMatchingProvider (0.12s)30712026/10/01 08:28:31 http: TLS handshake error from 127.0.0.1:36564: remote error: tls: bad certificate3072--- PASS: TestNewValidator_KubernetesRequiresCA (0.12s)30732026/10/01 08:28:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34313/oidc3074--- PASS: TestValidateToken_ValidToken (0.14s)30752026/10/01 08:28:31 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41409/oidc30762026/10/01 08:28:31 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34023/oidc3077--- PASS: TestValidateToken_MultipleProviders (0.18s)3078PASS3079Running hook tests...3080=== RUN TestSendPathsEmpty3081=== PAUSE TestSendPathsEmpty3082=== RUN TestQueueEnqueueAndFetch3083=== PAUSE TestQueueEnqueueAndFetch3084=== RUN TestQueueDeduplication3085=== PAUSE TestQueueDeduplication3086=== RUN TestQueueRemove3087=== PAUSE TestQueueRemove3088=== RUN TestQueueFetchBatchLimit3089=== PAUSE TestQueueFetchBatchLimit3090=== RUN TestQueueRetryMovesToBack3091=== PAUSE TestQueueRetryMovesToBack3092=== RUN TestQueueFetchRemoveLifecycle3093=== PAUSE TestQueueFetchRemoveLifecycle3094=== RUN TestQueueConcurrentWriters3095=== PAUSE TestQueueConcurrentWriters3096=== RUN TestQueueRemoveLargeClosure3097=== PAUSE TestQueueRemoveLargeClosure3098=== RUN TestServerClientIntegration3099=== PAUSE TestServerClientIntegration3100=== RUN TestServerQueueError3101=== PAUSE TestServerQueueError3102=== RUN TestGetListenerSocketActivation3103 server_test.go:210: === RUN TestGetListenerSocketActivation3104 --- PASS: TestGetListenerSocketActivation (0.00s)3105 PASS3106 3107--- PASS: TestGetListenerSocketActivation (0.01s)3108=== RUN TestDrainIsolatesPoisonPath3109=== PAUSE TestDrainIsolatesPoisonPath3110=== RUN TestRunNotBlockedByPoisonHead3111=== PAUSE TestRunNotBlockedByPoisonHead3112=== RUN TestDrainGivesUpWhenServerDown3113=== PAUSE TestDrainGivesUpWhenServerDown3114=== RUN TestFailedPathPrunedByLaterClosure3115=== PAUSE TestFailedPathPrunedByLaterClosure3116=== RUN TestWorkerUploadsAndRemoves3117=== PAUSE TestWorkerUploadsAndRemoves3118=== RUN TestWorkerSkipsGCdPaths3119=== PAUSE TestWorkerSkipsGCdPaths3120=== RUN TestWorkerPrunesClosureDeps3121=== PAUSE TestWorkerPrunesClosureDeps3122=== RUN TestDrainTimeout3123=== PAUSE TestDrainTimeout3124=== CONT TestSendPathsEmpty3125=== CONT TestServerQueueError3126--- PASS: TestSendPathsEmpty (0.00s)3127=== CONT TestServerClientIntegration3128=== CONT TestQueueRemoveLargeClosure3129=== CONT TestQueueConcurrentWriters3130=== CONT TestQueueFetchRemoveLifecycle3131=== CONT TestQueueRetryMovesToBack3132=== CONT TestQueueFetchBatchLimit3133=== CONT TestQueueRemove3134=== CONT TestQueueDeduplication3135=== CONT TestQueueEnqueueAndFetch31362026/10/01 08:28:31 ERROR Failed to queue paths error="permission denied" count=13137=== CONT TestDrainGivesUpWhenServerDown3138=== CONT TestFailedPathPrunedByLaterClosure3139=== CONT TestWorkerSkipsGCdPaths3140=== CONT TestDrainTimeout3141=== CONT TestRunNotBlockedByPoisonHead3142=== CONT TestDrainIsolatesPoisonPath3143=== CONT TestWorkerUploadsAndRemoves3144=== CONT TestWorkerPrunesClosureDeps3145--- PASS: TestServerQueueError (0.00s)3146--- PASS: TestServerClientIntegration (0.00s)3147--- PASS: TestQueueEnqueueAndFetch (0.02s)31482026/10/01 08:28:31 INFO Uploading batch count=231492026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=231502026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1619289451/002/a31512026/10/01 08:28:31 INFO Upload queue status pending=23152--- PASS: TestQueueFetchBatchLimit (0.02s)31532026/10/01 08:28:31 INFO Uploading batch count=131542026/10/01 08:28:31 INFO Upload queue status pending=231552026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1619289451/002/b31562026/10/01 08:28:31 INFO Upload queue status pending=33157--- PASS: TestQueueFetchRemoveLifecycle (0.02s)31582026/10/01 08:28:31 INFO Upload queue status pending=231592026/10/01 08:28:31 INFO Uploading batch count=23160--- PASS: TestQueueRetryMovesToBack (0.02s)31612026/10/01 08:28:31 INFO Uploading batch count=431622026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=431632026/10/01 08:28:31 INFO Uploading batch count=131642026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=131652026/10/01 08:28:31 INFO Uploading batch count=231662026/10/01 08:28:31 INFO Uploading batch count=131672026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=131682026/10/01 08:28:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3907199913/002/nonexistent31692026/10/01 08:28:31 INFO Uploading batch count=23170--- PASS: TestQueueDeduplication (0.02s)31712026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=231722026/10/01 08:28:31 INFO Uploading batch count=131732026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1619289451/002/c3174--- PASS: TestQueueRemove (0.02s)31752026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2694767906/002/bbb31762026/10/01 08:28:31 INFO Uploading batch count=131772026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1619289451/002/d31782026/10/01 08:28:31 INFO Uploading batch count=131792026/10/01 08:28:31 INFO Uploading batch count=231802026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=231812026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1619289451/002/e31822026/10/01 08:28:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1619289451/002/f31832026/10/01 08:28:31 ERROR Drain finished with paths left in queue remaining=1031842026/10/01 08:28:31 INFO Uploading batch count=131852026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=131862026/10/01 08:28:31 INFO Uploading batch count=131872026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=13188--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)31892026/10/01 08:28:31 INFO Uploading batch count=131902026/10/01 08:28:31 ERROR Upload failed error="upload failed" count=13191--- PASS: TestDrainGivesUpWhenServerDown (0.03s)31922026/10/01 08:28:31 ERROR Drain finished with paths left in queue remaining=13193--- PASS: TestDrainIsolatesPoisonPath (0.03s)3194--- PASS: TestWorkerUploadsAndRemoves (0.04s)3195--- PASS: TestWorkerSkipsGCdPaths (0.04s)3196--- PASS: TestWorkerPrunesClosureDeps (0.04s)3197--- PASS: TestQueueRemoveLargeClosure (0.07s)31982026/10/01 08:28:31 ERROR Upload failed error="context deadline exceeded" count=231992026/10/01 08:28:31 ERROR Drain finished with paths left in queue remaining=43200--- PASS: TestDrainTimeout (0.22s)3201--- PASS: TestQueueConcurrentWriters (0.38s)32022026/10/01 08:28:32 INFO Uploading batch count=132032026/10/01 08:28:32 INFO Uploading batch count=132042026/10/01 08:28:32 INFO Uploading batch count=132052026/10/01 08:28:32 ERROR Upload failed error="upload failed" count=132062026/10/01 08:28:32 INFO Uploading batch count=132072026/10/01 08:28:32 ERROR Upload failed error="upload failed" count=132082026/10/01 08:28:32 INFO Uploading batch count=132092026/10/01 08:28:32 ERROR Upload failed error="upload failed" count=132102026/10/01 08:28:32 INFO Uploading batch count=132112026/10/01 08:28:32 ERROR Upload failed error="upload failed" count=132122026/10/01 08:28:32 ERROR Drain finished with paths left in queue remaining=13213--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3214PASS