niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #303
· raw
1tribuchet: building on eliza2Running 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 TestScriptTokenCachesUntilRefresh96=== CONT TestUploadMultipart_SupersededByPeer97=== CONT TestDoServerRequestAttachesToken98=== CONT TestScriptTokenScriptFails99=== CONT TestScriptTokenNoExpiryRerunsEveryCall100=== CONT TestFileTokenEmpty101=== CONT TestFileTokenMissing102=== CONT TestFileTokenReadsAndCaches103=== CONT TestResolveStorePath104=== CONT TestStaticToken105=== CONT TestSetClientTLSErrors106=== CONT TestSetClientTLSDoesNotMutateDefaultTransport107=== CONT TestSetClientTLS108=== CONT TestClientSignaturesByStorePath109=== CONT TestDoWithRetry_BodyReplayedViaGetBody110=== CONT TestStreamPushIsolatesFailures111=== CONT TestStreamPushReportsSignatures112=== CONT TestStreamPushRequestLine113=== CONT TestGetStorePathHash114=== CONT TestConvertHashToNix32115=== CONT TestEncodeNixBase32WithRealHash116=== CONT TestEncodeNixBase32117=== CONT TestDumpPathWriterError118=== CONT TestDumpPathSingleFile119=== CONT TestDumpPathMatchesNix120=== CONT TestScriptTokenEmptyCommand121=== CONT TestPathInfoHashCompatibility122=== RUN TestUploadMultipart_SupersededByPeer/exists123--- PASS: TestFileTokenEmpty (0.00s)124=== CONT TestStreamPushBatchesUnderLoad125=== CONT TestStreamPushGivesUpOnDeadServer126=== PAUSE TestUploadMultipart_SupersededByPeer/exists127=== RUN TestUploadMultipart_SupersededByPeer/missing128=== PAUSE TestUploadMultipart_SupersededByPeer/missing129=== CONT TestShellSplitErrors130--- PASS: TestScriptTokenScriptFails (0.00s)131--- PASS: TestStaticToken (0.00s)132--- PASS: TestClientSignaturesByStorePath (0.00s)133--- PASS: TestFileTokenMissing (0.00s)134--- PASS: TestEncodeNixBase32WithRealHash (0.00s)135--- PASS: TestFileTokenReadsAndCaches (0.00s)136--- PASS: TestScriptTokenEmptyCommand (0.00s)137--- PASS: TestShellSplitErrors (0.00s)138=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1392026/10/01 08:30:40 ERROR Upload failed error="connection refused" count=201402026/10/01 08:30:40 ERROR Server seems unavailable, giving up on batch untried=17141=== CONT TestRateLimiterFeedback1422026/10/01 08:30:40 WARN Rate limiter enabled after throttle name=server-test rate=5143--- PASS: TestResolveStorePath (0.00s)144=== RUN TestRateLimiterFeedback/429_enables_limiter145=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)146=== RUN TestEncodeNixBase32/test_string_hash147=== CONT TestStreamPushReportsEveryPath1482026/10/01 08:30:40 ERROR Upload failed error="bad path" count=3149=== RUN TestConvertHashToNix32/SRI_format_to_Nix32150=== CONT TestScriptTokenBadJSON1512026/10/01 08:30:40 WARN Rate limiter enabled after throttle name=server-test rate=51522026/10/01 08:30:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35831153=== RUN TestGetStorePathHash/valid_store_path154=== CONT TestParsePathInfoJSONMultiplePaths155=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths156=== RUN TestSetClientTLSErrors/missing_cert_file157=== PAUSE TestGetStorePathHash/valid_store_path1582026/10/01 08:30:40 WARN Rate limiter backed off name=server-test rate=51592026/10/01 08:30:40 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35831160=== PAUSE TestRateLimiterFeedback/429_enables_limiter161=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== PAUSE TestEncodeNixBase32/test_string_hash163=== PAUSE TestSetClientTLSErrors/missing_cert_file164--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)165=== RUN TestGetStorePathHash/basename_without_hyphen_should_error166=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths167=== RUN TestSetClientTLS/rejects_connection_without_client_cert168=== CONT TestFilterOversizedClosures169=== CONT TestParsePathInfoJSON170=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32171=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error1722026/10/01 08:30:40 ERROR Upload failed error=boom count=1173=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon174--- PASS: TestStreamPushReportsEveryPath (0.00s)175--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)176--- PASS: TestStreamPushIsolatesFailures (0.01s)177=== RUN TestEncodeNixBase32/empty_input178=== RUN TestRateLimiterFeedback/503_enables_limiter179=== RUN TestSetClientTLSErrors/missing_key_file180=== CONT TestPathInfoCACompatibility181=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths182=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert183=== RUN TestParsePathInfoJSON/Nix_format184=== PAUSE TestParsePathInfoJSON/Nix_format185=== CONT TestPartSizeForNAR186=== CONT TestShellSplit187=== RUN TestFilterOversizedClosures/no_limit_keeps_everything188=== CONT TestCaseHackSuffix189=== RUN TestPartSizeForNAR/zero_stays_at_minimum190=== CONT TestRegisterUploadedObjectReusesConnections1912026/10/01 08:30:40 ERROR Upload failed error=boom count=1192=== CONT TestUploadMultipart_PartsInParallel193=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything194=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum195=== RUN TestConvertHashToNix32/already_Nix32_format196=== RUN TestPartSizeForNAR/small_stays_at_minimum197=== PAUSE TestPartSizeForNAR/small_stays_at_minimum198=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum199=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths200=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon201=== CONT TestUploadMultipart_SupersededByPeer/missing202=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI203--- PASS: TestScriptTokenBadJSON (0.01s)204=== CONT TestScriptTokenEmptyToken205=== PAUSE TestEncodeNixBase32/empty_input206=== PAUSE TestRateLimiterFeedback/503_enables_limiter207=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA208=== RUN TestParsePathInfoJSON/Lix_format209=== CONT TestUploadMultipart_SupersededByPeer/exists210=== PAUSE TestSetClientTLSErrors/missing_key_file211=== RUN TestPathInfoCACompatibility/null_ca_field212=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestConvertHashToNix32/already_Nix32_format214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum216--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)217--- PASS: TestDoServerRequestAttachesToken (0.02s)218--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)219--- PASS: TestShellSplit (0.00s)220--- PASS: TestStreamPushReportsSignatures (0.01s)221=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths223=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512224=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error225=== PAUSE TestPathInfoCACompatibility/null_ca_field226=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error227=== RUN TestPathInfoCACompatibility/old_string_format_-_text228=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text229=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error230=== RUN TestConvertHashToNix32/invalid_format231=== PAUSE TestConvertHashToNix32/invalid_format232=== CONT TestEncodeNixBase32/test_string_hash233=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive234=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive235=== RUN TestPathInfoCACompatibility/new_structured_format_-_text236=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text237=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method238=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method239=== CONT TestEncodeNixBase32/empty_input240--- PASS: TestEncodeNixBase32 (0.02s)241 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)242 --- PASS: TestEncodeNixBase32/empty_input (0.00s)243=== CONT TestGetStorePathHash/valid_store_path244=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter245=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter246=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter247=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter248=== CONT TestConvertHashToNix32/SRI_format_to_Nix32249=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error250=== CONT TestConvertHashToNix32/invalid_format251=== CONT TestConvertHashToNix32/already_Nix32_format252--- PASS: TestConvertHashToNix32 (0.04s)253 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)254 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)255 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)256=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error257=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method258=== CONT TestPathInfoCACompatibility/new_structured_format_-_text259=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive260=== CONT TestPathInfoCACompatibility/old_string_format_-_text261=== PAUSE TestParsePathInfoJSON/Lix_format262=== RUN TestSetClientTLSErrors/missing_ca_file263=== PAUSE TestSetClientTLSErrors/missing_ca_file264=== RUN TestSetClientTLSErrors/invalid_ca_file265=== PAUSE TestSetClientTLSErrors/invalid_ca_file266=== RUN TestParsePathInfoJSON/empty_input267=== PAUSE TestParsePathInfoJSON/empty_input268=== RUN TestParsePathInfoJSON/whitespace_only269=== PAUSE TestParsePathInfoJSON/whitespace_only270=== RUN TestParsePathInfoJSON/invalid_JSON271=== PAUSE TestParsePathInfoJSON/invalid_JSON272=== CONT TestGetStorePathHash/basename_without_hyphen_should_error273--- PASS: TestGetStorePathHash (0.04s)274 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)275 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)276 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)277 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)278=== CONT TestRateLimiterFeedback/503_enables_limiter279=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter280=== CONT TestSetClientTLSErrors/invalid_ca_file281=== CONT TestSetClientTLSErrors/missing_ca_file282--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)283 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)284 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.03s)285=== CONT TestSetClientTLSErrors/missing_key_file286=== CONT TestParsePathInfoJSON/Nix_format287=== CONT TestParsePathInfoJSON/invalid_JSON288=== CONT TestParsePathInfoJSON/empty_input289=== CONT TestParsePathInfoJSON/Lix_format290=== CONT TestParsePathInfoJSON/whitespace_only291=== CONT TestSetClientTLSErrors/missing_cert_file292--- PASS: TestParsePathInfoJSON (0.03s)293 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)294 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)295 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)296 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)297 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)298=== CONT TestRateLimiterFeedback/429_enables_limiter2992026/10/01 08:30:40 WARN Rate limiter enabled after throttle name=server-test rate=53002026/10/01 08:30:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:37625301=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter302--- PASS: TestSetClientTLSErrors (0.04s)303 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)304 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)305 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)306 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)3072026/10/01 08:30:40 WARN Rate limiter backed off name=server-test rate=5308=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA309=== RUN TestSetClientTLS/preserves_debug_logging_transport310=== PAUSE TestSetClientTLS/preserves_debug_logging_transport311=== CONT TestSetClientTLS/rejects_connection_without_client_cert312=== CONT TestSetClientTLS/preserves_debug_logging_transport313=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA314=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts315=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts316=== RUN TestPartSizeForNAR/1_TiB317=== PAUSE TestPartSizeForNAR/1_TiB318=== RUN TestPartSizeForNAR/5_TiB_S3_max_object319=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object320=== RUN TestPartSizeForNAR/capped_at_5_GiB321=== PAUSE TestPartSizeForNAR/capped_at_5_GiB322=== CONT TestPartSizeForNAR/zero_stays_at_minimum323=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512324=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)325=== CONT TestPartSizeForNAR/capped_at_5_GiB326=== CONT TestPartSizeForNAR/5_TiB_S3_max_object327=== CONT TestPartSizeForNAR/1_TiB328=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts329=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum330=== CONT TestPartSizeForNAR/small_stays_at_minimum331--- PASS: TestPartSizeForNAR (0.03s)332 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)333 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)334 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)335 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)336 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)337 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)338 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)339=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped340=== RUN TestFilterOversizedClosures/all_closures_skipped3412026/10/01 08:30:40 WARN Rate limiter enabled after throttle name=server-test rate=5342=== PAUSE TestFilterOversizedClosures/all_closures_skipped3432026/10/01 08:30:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35757344=== CONT TestFilterOversizedClosures/no_limit_keeps_everything345=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths346--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)347 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)348 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)349=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512350=== CONT TestPathInfoCACompatibility/null_ca_field351--- PASS: TestPathInfoCACompatibility (0.03s)352 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)353 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)354 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)355 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)356 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)357=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI358=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon359--- PASS: TestPathInfoHashCompatibility (0.04s)360 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)361 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)362 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)364=== CONT TestFilterOversizedClosures/all_closures_skipped365--- PASS: TestScriptTokenEmptyToken (0.01s)366=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3672026/10/01 08:30:40 WARN Rate limiter backed off name=server-test rate=53682026/10/01 08:30:40 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=20003692026/10/01 08:30:40 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50370--- PASS: TestFilterOversizedClosures (0.03s)371 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)372 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)373 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.01s)374--- PASS: TestDumpPathSingleFile (0.05s)375--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)376--- PASS: TestRateLimiterFeedback (0.04s)377 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)380 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)3812026/10/01 08:30:40 http: TLS handshake error from 127.0.0.1:46336: remote error: tls: bad certificate382--- PASS: TestCaseHackSuffix (0.06s)383--- PASS: TestSetClientTLS (0.05s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)387--- PASS: TestStreamPushRequestLine (0.08s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)389--- PASS: TestDumpPathWriterError (0.09s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres2791832420/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/postgres2791832420/data -l logfile start422423/build/postgres2791832420:5432 - no response4242026-10-01 08:30:42.640 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 08:30:42.640 UTC [128] LOG: listening on Unix socket "/build/postgres2791832420/.s.PGSQL.5432"4262026-10-01 08:30:42.644 UTC [135] LOG: database system was shut down at 2026-10-01 08:30:42 UTC4272026-10-01 08:30:42.648 UTC [128] LOG: database system is ready to accept connections428/build/postgres2791832420:5432 - accepting connections429{"timestamp":"2026-10-01T08:30:42.840462873Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7d93ec9a-e61d-49ee-b94f-2bfd30b1695b","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(202)"}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:30:43.018 UTC [371] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 08:30:43.018 UTC [371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 08:30:43 OK 20241026095416_initial_model.sql (10.91ms)4742026/10/01 08:30:43 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)4752026/10/01 08:30:43 OK 20251218171726_add_pins.sql (2.74ms)4762026/10/01 08:30:43 OK 20260628120000_add_object_size_and_stats.sql (2.56ms)4772026/10/01 08:30:43 OK 20260905000000_add_claims.sql (2.89ms)4782026/10/01 08:30:43 OK 20260920000000_drop_claims.sql (1.8ms)4792026/10/01 08:30:43 OK 20260923120000_add_pushes.sql (1.3ms)4802026/10/01 08:30:43 goose: successfully migrated database to version: 202609231200004812026/10/01 08:30:43 OK 1_commit_pending_closure.sql (1.63ms)4822026/10/01 08:30:43 OK 2_object_stats_trigger.sql (703.57µs)4832026/10/01 08:30:43 OK 3_commit_push.sql (569.77µs)4842026/10/01 08:30:43 goose: up to current file version: 34852026/10/01 08:30:43 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 08:30:43 INFO lead: released remote=192.0.2.1:12344872026/10/01 08:30:43 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 08:30:43 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 08:30:43.780 UTC [382] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 08:30:43.780 UTC [382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 08:30:43 OK 20241026095416_initial_model.sql (9.17ms)4962026/10/01 08:30:43 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)4972026/10/01 08:30:43 OK 20251218171726_add_pins.sql (3.18ms)4982026/10/01 08:30:43 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)4992026/10/01 08:30:43 OK 20260905000000_add_claims.sql (3.05ms)5002026/10/01 08:30:43 OK 20260920000000_drop_claims.sql (1.81ms)5012026/10/01 08:30:43 OK 20260923120000_add_pushes.sql (1.49ms)5022026/10/01 08:30:43 goose: successfully migrated database to version: 202609231200005032026/10/01 08:30:43 OK 1_commit_pending_closure.sql (1.79ms)5042026/10/01 08:30:43 OK 2_object_stats_trigger.sql (971.49µs)5052026/10/01 08:30:43 OK 3_commit_push.sql (673.59µs)5062026/10/01 08:30:43 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestGCTaskStore_StartNew539=== PAUSE TestGCTaskStore_StartNew540=== RUN TestGCTaskStore_DeduplicateSameParams541=== PAUSE TestGCTaskStore_DeduplicateSameParams542=== RUN TestGCTaskStore_ConflictDifferentParams543=== PAUSE TestGCTaskStore_ConflictDifferentParams544=== RUN TestGCTaskStore_GetEmpty545=== PAUSE TestGCTaskStore_GetEmpty546=== RUN TestGCTaskStore_GetReturnsLatest547=== PAUSE TestGCTaskStore_GetReturnsLatest548=== RUN TestGCTaskStore_CompletedAllowsNewTask549=== PAUSE TestGCTaskStore_CompletedAllowsNewTask550=== RUN TestGCTaskStore_PhaseUpdates551=== PAUSE TestGCTaskStore_PhaseUpdates552=== RUN TestGCTaskStore_Fail553=== PAUSE TestGCTaskStore_Fail554=== RUN TestGracefulShutdownDrainsInflight555=== PAUSE TestGracefulShutdownDrainsInflight556=== RUN TestService_healthCheckHandler557=== PAUSE TestService_healthCheckHandler558=== RUN TestService_readinessHandler559=== PAUSE TestService_readinessHandler560=== RUN TestGenerateLandingPage561=== PAUSE TestGenerateLandingPage562=== RUN TestCacheConfigHandlerMaxNarSize563=== PAUSE TestCacheConfigHandlerMaxNarSize564=== RUN TestCreatePendingClosureRejectsOversizedNAR565=== PAUSE TestCreatePendingClosureRejectsOversizedNAR566=== RUN TestNARDeduplicationMetadataUploadBug567=== PAUSE TestNARDeduplicationMetadataUploadBug568=== RUN TestMetricsInventory569=== PAUSE TestMetricsInventory570=== RUN TestService_NativeMTLS571=== PAUSE TestService_NativeMTLS572=== RUN TestServerTLSConfig573=== PAUSE TestServerTLSConfig574=== RUN TestMultipartCleanup575=== PAUSE TestMultipartCleanup576=== RUN TestObjectStatsTrigger577=== PAUSE TestObjectStatsTrigger578=== RUN TestOrphanedObjectsGC579=== PAUSE TestOrphanedObjectsGC580=== RUN TestOrphanedObjectsGCStressTest581=== PAUSE TestOrphanedObjectsGCStressTest582=== RUN TestCreatePin_ReservedPins583=== PAUSE TestCreatePin_ReservedPins584=== RUN TestParseSingleRange585=== PAUSE TestParseSingleRange586=== RUN TestProxyHeadersOnlyTrustedOnSocket587=== PAUSE TestProxyHeadersOnlyTrustedOnSocket588=== RUN TestIsValidCachePath589=== PAUSE TestIsValidCachePath590=== RUN TestReadProxyNarinfo591=== PAUSE TestReadProxyNarinfo592=== RUN TestReadProxyNarinfoAlreadyDecompressed593=== PAUSE TestReadProxyNarinfoAlreadyDecompressed594=== RUN TestReadProxyNarStreaming595=== PAUSE TestReadProxyNarStreaming596=== RUN TestReadProxy404597=== PAUSE TestReadProxy404598=== RUN TestReadProxyInvalidPath599=== PAUSE TestReadProxyInvalidPath600=== RUN TestReadProxyHead601=== PAUSE TestReadProxyHead602=== RUN TestReadProxyConditionalGet603=== PAUSE TestReadProxyConditionalGet604=== RUN TestReadProxyRootRedirectsToIndexHTML605=== PAUSE TestReadProxyRootRedirectsToIndexHTML606=== RUN TestReadProxyDisabled607=== PAUSE TestReadProxyDisabled608=== RUN TestReadRedirectNar609=== PAUSE TestReadRedirectNar610=== RUN TestReadRedirectKeepsNarinfoProxied611=== PAUSE TestReadRedirectKeepsNarinfoProxied612=== RUN TestReadProxyRangeRequest613=== PAUSE TestReadProxyRangeRequest614=== RUN TestReadRedirectUsesPublicS3URL615=== PAUSE TestReadRedirectUsesPublicS3URL616=== RUN TestPush_OverlappingRootsStoreOneRowPerKey617=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey618=== RUN TestPush_CompleteCommitsEveryRoot619=== PAUSE TestPush_CompleteCommitsEveryRoot620=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit621=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit622=== RUN TestPush_RejectsBadRequests623=== PAUSE TestPush_RejectsBadRequests624=== RUN TestPush_SignsNarinfosOfItsPendingObjects625=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects626=== RUN TestRedundantMultipartUpload627=== PAUSE TestRedundantMultipartUpload628=== RUN TestCompleteMultipartUpload_ErrorButObjectExists629=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists630=== RUN TestCompletedNarNotReofferedAcrossClosures631=== PAUSE TestCompletedNarNotReofferedAcrossClosures632=== RUN TestPresignedUploadRegisteredBeforeCommit633=== PAUSE TestPresignedUploadRegisteredBeforeCommit634=== RUN TestService_Rustfstest635=== PAUSE TestService_Rustfstest636=== RUN TestParseSize637=== PAUSE TestParseSize638=== RUN TestSkippedUploadsHandler639=== PAUSE TestSkippedUploadsHandler640=== RUN TestSystemdListenerNotActivated641--- PASS: TestSystemdListenerNotActivated (0.00s)642=== RUN TestWatchdogBeatsWhenHealthy643--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)644=== RUN TestWatchdogSkipsWhenUnhealthy6452026/10/01 08:30:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 08:30:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 08:30:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:30:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:30:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:30:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 08:30:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 08:30:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 08:30:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 08:30:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"655--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)656=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle657=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle658=== RUN TestProxyWriteTimeout659=== PAUSE TestProxyWriteTimeout660=== RUN TestIsValidUploadKey661=== PAUSE TestIsValidUploadKey662=== RUN TestUploadHandlersRejectInvalidKeys663=== PAUSE TestUploadHandlersRejectInvalidKeys664=== RUN TestUploadHandlersRejectOversizedBody665=== PAUSE TestUploadHandlersRejectOversizedBody666=== RUN TestService_cleanupPendingClosuresHandler667=== PAUSE TestService_cleanupPendingClosuresHandler668=== RUN TestService_createPendingClosureHandler669=== PAUSE TestService_createPendingClosureHandler670=== RUN TestService_verifyS3Integrity671=== PAUSE TestService_verifyS3Integrity672=== RUN TestCompleteMultipartUnregistered673=== PAUSE TestCompleteMultipartUnregistered674=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT675=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT676=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle677=== CONT TestService_cleanupPendingClosuresHandler678=== CONT TestService_AuthMiddleware679=== CONT TestSkippedUploadsHandler680=== CONT TestParseSize681--- PASS: TestParseSize (0.00s)682=== CONT TestReadProxy404683=== CONT TestService_Rustfstest684=== CONT TestPresignedUploadRegisteredBeforeCommit685=== CONT TestCompletedNarNotReofferedAcrossClosures686=== CONT TestCompleteMultipartUpload_ErrorButObjectExists6872026/10/01 08:30:44 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000688=== CONT TestRedundantMultipartUpload689=== CONT TestPush_SignsNarinfosOfItsPendingObjects690=== CONT TestPush_RejectsBadRequests691=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit692=== CONT TestPush_CompleteCommitsEveryRoot693=== CONT TestPush_OverlappingRootsStoreOneRowPerKey694=== CONT TestReadRedirectUsesPublicS3URL695=== CONT TestReadProxyRangeRequest696=== CONT TestReadRedirectKeepsNarinfoProxied697=== CONT TestReadRedirectNar698=== CONT TestReadProxyDisabled699=== CONT TestReadProxyRootRedirectsToIndexHTML700=== CONT TestReadProxyConditionalGet701=== CONT TestReadProxyHead702=== CONT TestReadProxyInvalidPath703--- PASS: TestSkippedUploadsHandler (0.01s)704=== CONT TestReadProxyNarStreaming7052026-10-01 08:30:44.198 UTC [448] ERROR: relation "goose_db_version" does not exist at character 367062026-10-01 08:30:44.198 UTC [448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026-10-01 08:30:44.199 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367082026-10-01 08:30:44.199 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026-10-01 08:30:44.224 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367102026-10-01 08:30:44.224 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7112026-10-01 08:30:44.235 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367122026-10-01 08:30:44.235 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-10-01 08:30:44.290 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367142026-10-01 08:30:44.290 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-10-01 08:30:44.300 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367162026-10-01 08:30:44.300 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026/10/01 08:30:44 OK 20241026095416_initial_model.sql (95.33ms)7182026/10/01 08:30:44 OK 20241026095416_initial_model.sql (95.19ms)7192026-10-01 08:30:44.319 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367202026-10-01 08:30:44.319 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7212026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (5.52ms)7222026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (5.29ms)7232026/10/01 08:30:44 OK 20241026095416_initial_model.sql (60.06ms)7242026/10/01 08:30:44 OK 20251218171726_add_pins.sql (28.95ms)7252026/10/01 08:30:44 OK 20251218171726_add_pins.sql (28.91ms)7262026/10/01 08:30:44 OK 20241026095416_initial_model.sql (44.77ms)7272026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)7282026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (6.91ms)7292026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)7302026-10-01 08:30:44.364 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367312026-10-01 08:30:44.364 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (14.76ms)7332026/10/01 08:30:44 OK 20251218171726_add_pins.sql (12.86ms)7342026/10/01 08:30:44 OK 20260905000000_add_claims.sql (11.73ms)7352026/10/01 08:30:44 OK 20241026095416_initial_model.sql (48.57ms)7362026/10/01 08:30:44 OK 20241026095416_initial_model.sql (47.82ms)7372026/10/01 08:30:44 OK 20251218171726_add_pins.sql (12.18ms)7382026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.11ms)7392026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)7402026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)7412026/10/01 08:30:44 OK 20260905000000_add_claims.sql (5.59ms)7422026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)7432026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.63ms)7442026/10/01 08:30:44 OK 20241026095416_initial_model.sql (24.62ms)7452026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200007462026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)7472026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.64ms)7482026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.6ms)7492026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.64ms)7502026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)7512026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.11ms)7522026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.6ms)7532026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.15ms)7542026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200007552026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.97ms)7562026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.71ms)7572026/10/01 08:30:44 OK 3_commit_push.sql (1ms)7582026/10/01 08:30:44 goose: up to current file version: 37592026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)7602026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.2ms)7612026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)7622026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.73ms)7632026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.6ms)7642026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.24ms)7652026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200007662026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.19ms)7672026-10-01 08:30:44.385 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367682026-10-01 08:30:44.385 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026-10-01 08:30:44.386 UTC [463] ERROR: relation "goose_db_version" does not exist at character 367702026-10-01 08:30:44.386 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026-10-01 08:30:44.386 UTC [462] ERROR: relation "goose_db_version" does not exist at character 367722026-10-01 08:30:44.386 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.74ms)7742026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200007752026-10-01 08:30:44.386 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367762026-10-01 08:30:44.386 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-10-01 08:30:44.387 UTC [466] ERROR: relation "goose_db_version" does not exist at character 367782026-10-01 08:30:44.387 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-10-01 08:30:44.387 UTC [465] ERROR: relation "goose_db_version" does not exist at character 367802026-10-01 08:30:44.387 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.94ms)7822026-10-01 08:30:44.388 UTC [467] ERROR: relation "goose_db_version" does not exist at character 367832026-10-01 08:30:44.388 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026-10-01 08:30:44.388 UTC [469] ERROR: relation "goose_db_version" does not exist at character 367852026-10-01 08:30:44.388 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.24ms)7872026-10-01 08:30:44.388 UTC [468] ERROR: relation "goose_db_version" does not exist at character 367882026-10-01 08:30:44.388 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-10-01 08:30:44.389 UTC [470] ERROR: relation "goose_db_version" does not exist at character 367902026-10-01 08:30:44.389 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.24ms)7922026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)7932026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.66ms)7942026/10/01 08:30:44 OK 3_commit_push.sql (1.87ms)7952026/10/01 08:30:44 goose: up to current file version: 37962026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.42ms)7972026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.33ms)7982026-10-01 08:30:44.390 UTC [471] ERROR: relation "goose_db_version" does not exist at character 367992026-10-01 08:30:44.390 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8002026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.83ms)8012026/10/01 08:30:44 OK 3_commit_push.sql (1.67ms)8022026/10/01 08:30:44 goose: up to current file version: 38032026/10/01 08:30:44 OK 20241026095416_initial_model.sql (13.18ms)8042026/10/01 08:30:44 OK 3_commit_push.sql (1ms)8052026/10/01 08:30:44 goose: up to current file version: 38062026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.15ms)8072026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.34ms)8082026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.87ms)8092026-10-01 08:30:44.393 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368102026-10-01 08:30:44.393 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)8122026-10-01 08:30:44.394 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368132026-10-01 08:30:44.394 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-10-01 08:30:44.394 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368152026-10-01 08:30:44.394 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (5.4ms)8172026-10-01 08:30:44.398 UTC [476] ERROR: relation "goose_db_version" does not exist at character 368182026-10-01 08:30:44.398 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026-10-01 08:30:44.399 UTC [475] ERROR: relation "goose_db_version" does not exist at character 368202026-10-01 08:30:44.399 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (6.81ms)8222026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200008232026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (6.63ms)8242026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200008252026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.57ms)8262026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200008272026/10/01 08:30:44 OK 20251218171726_add_pins.sql (10.73ms)8282026/10/01 08:30:44 OK 1_commit_pending_closure.sql (4.73ms)8292026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.9ms)8302026/10/01 08:30:44 OK 1_commit_pending_closure.sql (5.01ms)8312026/10/01 08:30:44 OK 20241026095416_initial_model.sql (12.36ms)832--- PASS: TestReadProxy404 (0.34s)833=== CONT TestReadProxyNarinfoAlreadyDecompressed8342026/10/01 08:30:44 OK 20241026095416_initial_model.sql (13.46ms)8352026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.97ms)8362026/10/01 08:30:44 OK 2_object_stats_trigger.sql (3.12ms)8372026/10/01 08:30:44 OK 20241026095416_initial_model.sql (15.17ms)8382026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.78ms)8392026/10/01 08:30:44 OK 3_commit_push.sql (2.04ms)8402026/10/01 08:30:44 goose: up to current file version: 38412026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (4.84ms)8422026/10/01 08:30:44 OK 3_commit_push.sql (2.09ms)8432026/10/01 08:30:44 goose: up to current file version: 38442026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (6.8ms)8452026/10/01 08:30:44 OK 3_commit_push.sql (2.09ms)8462026/10/01 08:30:44 goose: up to current file version: 38472026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)8482026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)8492026/10/01 08:30:44 OK 20241026095416_initial_model.sql (13.95ms)8502026/10/01 08:30:44 OK 20241026095416_initial_model.sql (14.23ms)8512026/10/01 08:30:44 OK 20241026095416_initial_model.sql (13.93ms)8522026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.04ms)8532026/10/01 08:30:44 OK 20241026095416_initial_model.sql (15.82ms)8542026/10/01 08:30:44 OK 20241026095416_initial_model.sql (16.84ms)8552026/10/01 08:30:44 OK 20251218171726_add_pins.sql (6.26ms)8562026/10/01 08:30:44 OK 20241026095416_initial_model.sql (16.59ms)8572026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.6ms)8582026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.81ms)8592026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)8602026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)8612026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.2ms)8622026/10/01 08:30:44 OK 20241026095416_initial_model.sql (16.77ms)8632026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)8642026/10/01 08:30:44 OK 20241026095416_initial_model.sql (12.32ms)8652026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)8662026/10/01 08:30:44 OK 20241026095416_initial_model.sql (17.18ms)8672026/10/01 08:30:44 OK 20241026095416_initial_model.sql (15.11ms)8682026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)8692026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)8702026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.07ms)8712026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)8722026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)8732026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (3.05ms)8742026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200008752026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)8762026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)8772026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)8782026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)8792026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures8802026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.26ms)8812026/10/01 08:30:44 OK 20251218171726_add_pins.sql (5.01ms)8822026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)8832026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)8842026/10/01 08:30:44 OK 20241026095416_initial_model.sql (16.8ms)8852026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.49ms)8862026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.45ms)8872026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.81ms)8882026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.61ms)8892026/10/01 08:30:44 OK 20241026095416_initial_model.sql (14.75ms)8902026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.53ms)8912026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.34ms)8922026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)8932026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.5ms)8942026/10/01 08:30:44 OK 20260905000000_add_claims.sql (5.17ms)8952026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)8962026/10/01 08:30:44 OK 20260905000000_add_claims.sql (5.3ms)8972026/10/01 08:30:44 OK 20251218171726_add_pins.sql (5.05ms)8982026/10/01 08:30:44 OK 20251218171726_add_pins.sql (5.12ms)8992026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)9002026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.06ms)9012026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)9022026/10/01 08:30:44 OK 20251218171726_add_pins.sql (5.34ms)9032026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.75ms)9042026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.53ms)9052026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)9062026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)9072026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)9082026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.37ms)9092026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)9102026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.17ms)9112026/10/01 08:30:44 OK 3_commit_push.sql (2.2ms)9122026/10/01 08:30:44 goose: up to current file version: 39132026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.68ms)9142026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.26ms)9152026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)9162026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)9172026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.57ms)9182026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.47ms)9192026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.31ms)9202026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.85ms)9212026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009222026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.45ms)9232026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9242026/10/01 08:30:44 OK 20251218171726_add_pins.sql (5.19ms)9252026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.31ms)9262026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (3ms)9272026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009282026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9292026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.86ms)9302026/10/01 08:30:44 OK 20260905000000_add_claims.sql (5.3ms)9312026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)9322026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (4.48ms)9332026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009342026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.2ms)9352026/10/01 08:30:44 OK 20260905000000_add_claims.sql (5.38ms)9362026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.18ms)9372026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.52ms)9382026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.15ms)9392026/10/01 08:30:44 OK 20260905000000_add_claims.sql (5.74ms)9402026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.48ms)9412026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (4.39ms)9422026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (5.09ms)9432026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (5.25ms)9442026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.52ms)9452026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (5.3ms)9462026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (3.39ms)9472026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.73ms)9482026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.81ms)9492026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009502026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.85ms)9512026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.61ms)9522026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.79ms)9532026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.49ms)9542026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.65ms)9552026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.9ms)9562026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.99ms)9572026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.47ms)9582026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009592026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.73ms)9602026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009612026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.81ms)9622026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009632026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.87ms)9642026/10/01 08:30:44 OK 3_commit_push.sql (2.1ms)9652026/10/01 08:30:44 goose: up to current file version: 39662026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.49ms)9672026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009682026/10/01 08:30:44 OK 3_commit_push.sql (2.01ms)9692026/10/01 08:30:44 goose: up to current file version: 39702026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.3ms)9712026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (3.53ms)9722026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009732026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.47ms)9742026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.04ms)9752026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.25ms)9762026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009772026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (3.08ms)9782026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009792026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.99ms)9802026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (3.49ms)9812026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009822026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.07ms)9832026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.68ms)9842026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.79ms)9852026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009862026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.6ms)9872026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.63ms)9882026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.38ms)9892026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200009902026/10/01 08:30:44 OK 3_commit_push.sql (1.44ms)9912026/10/01 08:30:44 goose: up to current file version: 39922026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.07ms)9932026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.24ms)9942026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.7ms)9952026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.49ms)9962026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.23ms)9972026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.47ms)9982026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.48ms)9992026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000010002026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures10012026/10/01 08:30:44 OK 3_commit_push.sql (1.85ms)10022026/10/01 08:30:44 goose: up to current file version: 310032026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.88ms)10042026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.29ms)10052026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.05ms)10062026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.16ms)10072026/10/01 08:30:44 OK 3_commit_push.sql (1.34ms)10082026/10/01 08:30:44 goose: up to current file version: 310092026/10/01 08:30:44 OK 3_commit_push.sql (1.26ms)10102026/10/01 08:30:44 goose: up to current file version: 310112026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.94ms)10122026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.32ms)10132026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.98ms)10142026/10/01 08:30:44 OK 3_commit_push.sql (1.1ms)10152026/10/01 08:30:44 goose: up to current file version: 310162026/10/01 08:30:44 OK 1_commit_pending_closure.sql (1.82ms)10172026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.94ms)10182026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.72ms)10192026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.69ms)10202026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.8ms)10212026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000010222026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.78ms)10232026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.33ms)10242026/10/01 08:30:44 OK 3_commit_push.sql (1.39ms)10252026/10/01 08:30:44 goose: up to current file version: 310262026/10/01 08:30:44 OK 3_commit_push.sql (741.19µs)10272026/10/01 08:30:44 goose: up to current file version: 310282026/10/01 08:30:44 OK 3_commit_push.sql (1.3ms)10292026/10/01 08:30:44 goose: up to current file version: 310302026/10/01 08:30:44 OK 2_object_stats_trigger.sql (936.37µs)10312026/10/01 08:30:44 OK 3_commit_push.sql (615.53µs)10322026/10/01 08:30:44 goose: up to current file version: 310332026/10/01 08:30:44 OK 3_commit_push.sql (620.07µs)10342026/10/01 08:30:44 goose: up to current file version: 310352026/10/01 08:30:44 OK 3_commit_push.sql (813.03µs)10362026/10/01 08:30:44 goose: up to current file version: 310372026/10/01 08:30:44 OK 3_commit_push.sql (523.95µs)10382026/10/01 08:30:44 goose: up to current file version: 310392026/10/01 08:30:44 OK 3_commit_push.sql (703.85µs)10402026/10/01 08:30:44 goose: up to current file version: 310412026/10/01 08:30:44 OK 1_commit_pending_closure.sql (1.89ms)10422026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.25ms)10432026/10/01 08:30:44 OK 3_commit_push.sql (1.07ms)10442026/10/01 08:30:44 goose: up to current file version: 310452026/10/01 08:30:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10462026/10/01 08:30:44 INFO Aborted multipart uploads count=010472026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures10482026/10/01 08:30:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10492026/10/01 08:30:44 INFO Aborted multipart uploads count=110502026-10-01 08:30:44.477 UTC [480] ERROR: relation "goose_db_version" does not exist at character 3610512026-10-01 08:30:44.477 UTC [480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10522026/10/01 08:30:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10532026-10-01 08:30:44.479 UTC [451] ERROR: Closure does not exist: id=110542026-10-01 08:30:44.479 UTC [451] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10552026-10-01 08:30:44.479 UTC [451] STATEMENT: -- name: CommitPendingClosure :exec1056 SELECT commit_pending_closure($1::bigint)1057 1058--- PASS: TestService_cleanupPendingClosuresHandler (0.42s)1059=== CONT TestReadProxyNarinfo10602026/10/01 08:30:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1061--- PASS: TestService_AuthMiddleware (0.42s)1062=== CONT TestIsValidCachePath1063=== RUN TestIsValidCachePath/narinfo1064=== PAUSE TestIsValidCachePath/narinfo1065=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1066=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1067=== RUN TestIsValidCachePath/nar_zst1068=== PAUSE TestIsValidCachePath/nar_zst1069=== RUN TestIsValidCachePath/nar_xz1070=== PAUSE TestIsValidCachePath/nar_xz1071=== RUN TestIsValidCachePath/nar_bz21072=== PAUSE TestIsValidCachePath/nar_bz21073=== RUN TestIsValidCachePath/nar_uncompressed1074=== PAUSE TestIsValidCachePath/nar_uncompressed1075=== RUN TestIsValidCachePath/ls1076=== PAUSE TestIsValidCachePath/ls1077=== RUN TestIsValidCachePath/log1078=== PAUSE TestIsValidCachePath/log1079=== RUN TestIsValidCachePath/realisation1080=== PAUSE TestIsValidCachePath/realisation1081=== RUN TestIsValidCachePath/nix-cache-info1082=== PAUSE TestIsValidCachePath/nix-cache-info1083=== RUN TestIsValidCachePath/index.html1084=== PAUSE TestIsValidCachePath/index.html1085=== RUN TestIsValidCachePath/traversal_parent1086=== PAUSE TestIsValidCachePath/traversal_parent1087=== RUN TestIsValidCachePath/traversal_in_middle1088=== PAUSE TestIsValidCachePath/traversal_in_middle1089=== RUN TestIsValidCachePath/invalid_char_e1090=== PAUSE TestIsValidCachePath/invalid_char_e1091=== RUN TestIsValidCachePath/invalid_char_u1092=== PAUSE TestIsValidCachePath/invalid_char_u1093=== RUN TestIsValidCachePath/random_path1094=== PAUSE TestIsValidCachePath/random_path1095=== RUN TestIsValidCachePath/empty1096=== PAUSE TestIsValidCachePath/empty1097=== RUN TestIsValidCachePath/leading_slash1098=== PAUSE TestIsValidCachePath/leading_slash1099=== RUN TestIsValidCachePath/wrong_extension1100=== PAUSE TestIsValidCachePath/wrong_extension1101=== RUN TestIsValidCachePath/short_hash1102=== PAUSE TestIsValidCachePath/short_hash1103=== CONT TestProxyHeadersOnlyTrustedOnSocket11042026/10/01 08:30:44 OK 20241026095416_initial_model.sql (8.22ms)11052026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (6.63ms)11072026/10/01 08:30:44 OK 20251218171726_add_pins.sql (2.92ms)11082026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.43ms)11092026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.04ms)11102026/10/01 08:30:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11112026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2ms)11122026/10/01 08:30:44 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11132026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures11142026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.19ms)11152026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000011162026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures1117--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.45s)1118=== CONT TestUploadHandlersRejectInvalidKeys1119=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1120=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1121=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1122=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1123=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1124=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1125=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1126=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1127=== CONT TestUploadHandlersRejectOversizedBody11282026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.95ms)11292026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.75ms)11302026/10/01 08:30:44 OK 3_commit_push.sql (1.04ms)11312026/10/01 08:30:44 goose: up to current file version: 311322026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures1133--- PASS: TestService_Rustfstest (0.47s)1134=== CONT TestParseSingleRange1135=== RUN TestParseSingleRange/none1136=== PAUSE TestParseSingleRange/none1137=== RUN TestParseSingleRange/unknown_unit1138=== PAUSE TestParseSingleRange/unknown_unit1139=== RUN TestParseSingleRange/multi-range_ignored1140=== PAUSE TestParseSingleRange/multi-range_ignored1141=== RUN TestParseSingleRange/malformed_no_dash1142=== PAUSE TestParseSingleRange/malformed_no_dash1143=== RUN TestParseSingleRange/malformed_both_empty1144=== PAUSE TestParseSingleRange/malformed_both_empty1145=== RUN TestParseSingleRange/malformed_end_before_start1146=== PAUSE TestParseSingleRange/malformed_end_before_start1147=== RUN TestParseSingleRange/closed1148=== PAUSE TestParseSingleRange/closed1149=== RUN TestParseSingleRange/open-ended1150=== PAUSE TestParseSingleRange/open-ended1151=== RUN TestParseSingleRange/end_clamped_to_size1152=== PAUSE TestParseSingleRange/end_clamped_to_size1153=== RUN TestParseSingleRange/suffix1154=== PAUSE TestParseSingleRange/suffix1155=== RUN TestParseSingleRange/suffix_exceeds_size1156=== PAUSE TestParseSingleRange/suffix_exceeds_size1157=== RUN TestParseSingleRange/single_byte1158=== PAUSE TestParseSingleRange/single_byte1159=== RUN TestParseSingleRange/start_past_EOF1160=== PAUSE TestParseSingleRange/start_past_EOF1161=== RUN TestParseSingleRange/start_far_past_EOF1162=== PAUSE TestParseSingleRange/start_far_past_EOF1163=== CONT TestFailedS3DeleteKeepsTombstone1164--- PASS: TestReadProxyDisabled (0.51s)1165=== CONT TestForceGCDuringPushOffersSweptObject1166=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1167=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1168=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1169=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1170=== CONT TestCreatePin_ReservedPins11712026-10-01 08:30:44.584 UTC [485] ERROR: relation "goose_db_version" does not exist at character 3611722026-10-01 08:30:44.584 UTC [485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11732026-10-01 08:30:44.585 UTC [487] ERROR: relation "goose_db_version" does not exist at character 3611742026-10-01 08:30:44.585 UTC [487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/10/01 08:30:44 OK 20241026095416_initial_model.sql (10.31ms)1176=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1177=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1178=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1179=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1180=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1181=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1182=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11832026/10/01 08:30:44 OK 20241026095416_initial_model.sql (76.7ms)11842026/10/01 08:30:44 INFO Received push request method=POST path=/api/pushes11852026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)11862026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)1187--- PASS: TestReadRedirectNar (0.61s)1188=== CONT TestOrphanedObjectsGCStressTest11892026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.6ms)11902026-10-01 08:30:44.677 UTC [490] ERROR: relation "goose_db_version" does not exist at character 3611912026-10-01 08:30:44.677 UTC [490] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.04ms)11932026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)11942026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)11952026/10/01 08:30:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11962026/10/01 08:30:44 INFO Signed narinfos id=1 count=11197--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.62s)1198=== CONT TestGCSweepDeliversEachKeyOnce11992026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.48ms)12002026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.61ms)12012026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.75ms)12022026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.74ms)12032026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.18ms)12042026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000012052026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.37ms)12062026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000012072026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.51ms)12082026/10/01 08:30:44 OK 20241026095416_initial_model.sql (12.04ms)12092026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.8ms)12102026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.91ms)12112026/10/01 08:30:44 OK 3_commit_push.sql (1.25ms)12122026/10/01 08:30:44 goose: up to current file version: 312132026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.96ms)12142026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12152026/10/01 08:30:44 OK 3_commit_push.sql (1.46ms)12162026/10/01 08:30:44 goose: up to current file version: 312172026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.09ms)12182026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (10.28ms)1219--- PASS: TestReadRedirectUsesPublicS3URL (0.65s)1220=== CONT TestOrphanedObjectsGC12212026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.23ms)1222--- PASS: TestReadProxyInvalidPath (0.65s)1223=== CONT TestTombstonedObjectOfferedWithoutWaiting12242026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.83ms)12252026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.18ms)12262026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000012272026/10/01 08:30:44 OK 1_commit_pending_closure.sql (1.89ms)12282026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.33ms)12292026/10/01 08:30:44 OK 3_commit_push.sql (1.19ms)12302026/10/01 08:30:44 goose: up to current file version: 312312026/10/01 08:30:44 INFO Received push request method=POST path=/api/pushes12322026-10-01 08:30:44.749 UTC [501] ERROR: relation "goose_db_version" does not exist at character 3612332026-10-01 08:30:44.749 UTC [501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12342026-10-01 08:30:44.757 UTC [504] ERROR: relation "goose_db_version" does not exist at character 3612352026-10-01 08:30:44.757 UTC [504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/10/01 08:30:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12372026/10/01 08:30:44 INFO Received push request method=POST path=/api/pushes12382026-10-01 08:30:44.763 UTC [505] ERROR: relation "goose_db_version" does not exist at character 3612392026-10-01 08:30:44.763 UTC [505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1240--- PASS: TestPush_CompleteCommitsEveryRoot (0.70s)1241=== CONT TestGCSweepSkipsPendingObjects12422026/10/01 08:30:44 OK 20241026095416_initial_model.sql (17.21ms)12432026/10/01 08:30:44 OK 20241026095416_initial_model.sql (13.28ms)12442026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)12452026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)12462026/10/01 08:30:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45633/oidc1247--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.72s)1248=== CONT TestObjectStatsTrigger12492026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.95ms)1250=== RUN TestPush_RejectsBadRequests/no_objects1251=== PAUSE TestPush_RejectsBadRequests/no_objects1252=== RUN TestPush_RejectsBadRequests/bad_root1253=== PAUSE TestPush_RejectsBadRequests/bad_root1254=== RUN TestPush_RejectsBadRequests/root_not_in_objects1255=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1256=== RUN TestPush_RejectsBadRequests/no_roots1257=== PAUSE TestPush_RejectsBadRequests/no_roots1258=== CONT TestIsValidUploadKey1259=== RUN TestIsValidUploadKey/narinfo1260=== PAUSE TestIsValidUploadKey/narinfo1261=== RUN TestIsValidUploadKey/nar_zst1262=== PAUSE TestIsValidUploadKey/nar_zst1263=== RUN TestIsValidUploadKey/nar_xz1264=== PAUSE TestIsValidUploadKey/nar_xz1265=== RUN TestIsValidUploadKey/nar_plain1266=== PAUSE TestIsValidUploadKey/nar_plain1267=== RUN TestIsValidUploadKey/listing1268=== PAUSE TestIsValidUploadKey/listing1269=== RUN TestIsValidUploadKey/build_log1270=== PAUSE TestIsValidUploadKey/build_log1271=== RUN TestIsValidUploadKey/build_log_home-manager_file1272=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1273=== RUN TestIsValidUploadKey/build_log_plus_in_name1274=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1275=== RUN TestIsValidUploadKey/build_log_question_mark1276=== PAUSE TestIsValidUploadKey/build_log_question_mark1277=== RUN TestIsValidUploadKey/build_log_equals1278=== PAUSE TestIsValidUploadKey/build_log_equals1279=== RUN TestIsValidUploadKey/realisation1280=== PAUSE TestIsValidUploadKey/realisation1281=== RUN TestIsValidUploadKey/realisation_plus_in_output1282=== PAUSE TestIsValidUploadKey/realisation_plus_in_output12832026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.15ms)1284=== RUN TestIsValidUploadKey/nix-cache-info1285=== PAUSE TestIsValidUploadKey/nix-cache-info1286=== RUN TestIsValidUploadKey/index.html1287=== PAUSE TestIsValidUploadKey/index.html1288=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1289=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1290=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1291=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1292=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1293=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1294=== RUN TestIsValidUploadKey/traversal1295=== PAUSE TestIsValidUploadKey/traversal1296=== RUN TestIsValidUploadKey/traversal_nar1297=== PAUSE TestIsValidUploadKey/traversal_nar1298=== RUN TestIsValidUploadKey/absolute1299=== PAUSE TestIsValidUploadKey/absolute1300=== RUN TestIsValidUploadKey/empty_key1301=== PAUSE TestIsValidUploadKey/empty_key1302=== RUN TestIsValidUploadKey/unknown_type1303=== PAUSE TestIsValidUploadKey/unknown_type1304=== CONT TestMultipartCleanup13052026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)13062026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)13072026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.66ms)13082026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.15ms)13092026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.09ms)13102026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.89ms)13112026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)13122026-10-01 08:30:44.792 UTC [514] ERROR: relation "goose_db_version" does not exist at character 3613132026-10-01 08:30:44.792 UTC [514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13142026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.7ms)13152026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000013162026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.67ms)13172026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.01ms)13182026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.1ms)13192026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.83ms)13202026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000013212026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.32ms)13222026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)13232026/10/01 08:30:44 OK 3_commit_push.sql (1.49ms)13242026/10/01 08:30:44 goose: up to current file version: 313252026-10-01 08:30:44.799 UTC [516] ERROR: relation "goose_db_version" does not exist at character 3613262026-10-01 08:30:44.799 UTC [516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.11ms)13282026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.76ms)13292026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.63ms)13302026/10/01 08:30:44 OK 3_commit_push.sql (1.33ms)13312026/10/01 08:30:44 goose: up to current file version: 313322026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.53ms)13332026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.52ms)13342026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000013352026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.41ms)13362026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3ms)13372026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)13382026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.55ms)13392026/10/01 08:30:44 OK 3_commit_push.sql (1.26ms)13402026/10/01 08:30:44 goose: up to current file version: 313412026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.71ms)13422026/10/01 08:30:44 OK 20241026095416_initial_model.sql (12.68ms)13432026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)13442026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)13452026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.46ms)13462026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.82ms)1347--- PASS: TestReadProxyHead (0.76s)1348=== CONT TestDeduplicatedObjectsRecordedAsPending13492026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.69ms)13502026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.39ms)13512026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000013522026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)13532026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.29ms)1354--- PASS: TestReadProxyNarStreaming (0.77s)1355=== CONT TestServerTLSConfig1356=== RUN TestServerTLSConfig/no_client_CA1357=== PAUSE TestServerTLSConfig/no_client_CA1358=== RUN TestServerTLSConfig/missing_CA_file1359=== PAUSE TestServerTLSConfig/missing_CA_file1360=== RUN TestServerTLSConfig/not_a_PEM_file1361=== PAUSE TestServerTLSConfig/not_a_PEM_file1362=== CONT TestCompleteMultipartUnregistered13632026/10/01 08:30:44 OK 2_object_stats_trigger.sql (6.73ms)13642026/10/01 08:30:44 OK 20260905000000_add_claims.sql (9.62ms)13652026/10/01 08:30:44 OK 3_commit_push.sql (1.81ms)13662026/10/01 08:30:44 goose: up to current file version: 313672026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.96ms)13682026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.48ms)13692026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000013702026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.26ms)13712026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.1ms)13722026/10/01 08:30:44 OK 3_commit_push.sql (723.61µs)13732026/10/01 08:30:44 goose: up to current file version: 313742026-10-01 08:30:44.850 UTC [521] ERROR: relation "goose_db_version" does not exist at character 3613752026-10-01 08:30:44.850 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1376--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.79s)1377=== CONT TestPushDedupSurvivesConcurrentGC13782026-10-01 08:30:44.858 UTC [522] ERROR: relation "goose_db_version" does not exist at character 3613792026-10-01 08:30:44.858 UTC [522] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13802026-10-01 08:30:44.858 UTC [524] ERROR: relation "goose_db_version" does not exist at character 3613812026-10-01 08:30:44.858 UTC [524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13822026-10-01 08:30:44.860 UTC [525] ERROR: relation "goose_db_version" does not exist at character 3613832026-10-01 08:30:44.860 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13842026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.27ms)13852026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)13862026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.75ms)13872026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.25ms)13882026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.26ms)13892026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.39ms)13902026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)13912026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)13922026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)13932026/10/01 08:30:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13942026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)1395--- PASS: TestReadProxyRangeRequest (0.82s)1396=== CONT TestService_NativeMTLS13972026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.13ms)13982026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.75ms)13992026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.36ms)14002026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.43ms)14012026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.5ms)14022026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)14032026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)14042026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.45ms)14052026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000014062026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)14072026/10/01 08:30:44 OK 20260905000000_add_claims.sql (2.9ms)14082026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.32ms)14092026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.64ms)14102026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.71ms)14112026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.08ms)14122026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.81ms)14132026/10/01 08:30:44 OK 3_commit_push.sql (1.49ms)14142026/10/01 08:30:44 goose: up to current file version: 314152026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.13ms)14162026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (1.97ms)14172026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000014182026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (3.04ms)14192026/10/01 08:30:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTg3ZjZhOTYtZmEwNi00OTMyLWJkZjEtZWU1MDg1NjVhMDdkLjA2ZTZiYmQ2LWU4ODEtNGM2OC1hOTY2LTU3NmIyZjRhNTM2Y3gxNzkwODQzNDQ0NDMxMDA1MzYw parts=1214202026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures1421--- PASS: TestReadRedirectKeepsNarinfoProxied (0.84s)1422=== CONT TestGCMetrics14232026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (8.03ms)14242026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000014252026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (8.64ms)14262026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000014272026/10/01 08:30:44 OK 1_commit_pending_closure.sql (8.92ms)14282026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.12ms)14292026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.18ms)1430--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.84s)1431=== CONT TestMetricsInventory14322026/10/01 08:30:44 OK 2_object_stats_trigger.sql (2.08ms)14332026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.92ms)14342026/10/01 08:30:44 OK 3_commit_push.sql (1.46ms)14352026/10/01 08:30:44 goose: up to current file version: 314362026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.64ms)14372026/10/01 08:30:44 OK 3_commit_push.sql (1.69ms)14382026/10/01 08:30:44 goose: up to current file version: 314392026/10/01 08:30:44 OK 3_commit_push.sql (1.2ms)14402026/10/01 08:30:44 goose: up to current file version: 314412026-10-01 08:30:44.913 UTC [550] ERROR: relation "goose_db_version" does not exist at character 3614422026-10-01 08:30:44.913 UTC [550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14432026/10/01 08:30:44 INFO Received uploads request method=POST path=/api/pending_closures14442026-10-01 08:30:44.914 UTC [549] ERROR: relation "goose_db_version" does not exist at character 3614452026-10-01 08:30:44.914 UTC [549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14462026-10-01 08:30:44.927 UTC [552] ERROR: relation "goose_db_version" does not exist at character 3614472026-10-01 08:30:44.927 UTC [552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/10/01 08:30:44 OK 20241026095416_initial_model.sql (11.41ms)14492026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)14502026/10/01 08:30:44 OK 20241026095416_initial_model.sql (12.94ms)14512026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)14522026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.66ms)14532026/10/01 08:30:44 OK 20251218171726_add_pins.sql (3.63ms)14542026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)14552026/10/01 08:30:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14562026/10/01 08:30:44 OK 20241026095416_initial_model.sql (9.56ms)14572026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)14582026/10/01 08:30:44 OK 20260905000000_add_claims.sql (4.05ms)14592026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)14602026/10/01 08:30:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTg3ZjZhOTYtZmEwNi00OTMyLWJkZjEtZWU1MDg1NjVhMDdkLjE4MGU4NTlkLWFhNTQtNDNmOS04NDhmLTMyNTFmOGMwYmU0ZHgxNzkwODQzNDQ0OTIxMjI0NDQz1461--- PASS: TestReadProxyConditionalGet (0.88s)1462=== CONT TestGCBugBareHashReferences14632026/10/01 08:30:44 OK 20260905000000_add_claims.sql (3.12ms)14642026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.84ms)14652026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.22ms)14662026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.55ms)14672026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.92ms)14682026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000014692026/10/01 08:30:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTg3ZjZhOTYtZmEwNi00OTMyLWJkZjEtZWU1MDg1NjVhMDdkLjE4MGU4NTlkLWFhNTQtNDNmOS04NDhmLTMyNTFmOGMwYmU0ZHgxNzkwODQzNDQ0OTIxMjI0NDQz parts=114702026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.04ms)1471--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.89s)14722026/10/01 08:30:44 goose: successfully migrated database to version: 202609231200001473=== CONT TestNARDeduplicationMetadataUploadBug14742026/10/01 08:30:44 OK 1_commit_pending_closure.sql (2.34ms)14752026/10/01 08:30:44 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)14762026/10/01 08:30:44 OK 1_commit_pending_closure.sql (1.88ms)14772026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.28ms)14782026/10/01 08:30:44 OK 3_commit_push.sql (1.23ms)14792026/10/01 08:30:44 goose: up to current file version: 314802026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.38ms)14812026/10/01 08:30:44 OK 20260905000000_add_claims.sql (2.9ms)14822026/10/01 08:30:44 OK 3_commit_push.sql (1.09ms)14832026/10/01 08:30:44 goose: up to current file version: 314842026/10/01 08:30:44 OK 20260920000000_drop_claims.sql (2.12ms)14852026/10/01 08:30:44 INFO Received push request method=POST path=/api/pushes14862026/10/01 08:30:44 OK 20260923120000_add_pushes.sql (2.19ms)14872026/10/01 08:30:44 goose: successfully migrated database to version: 2026092312000014882026-10-01 08:30:44.962 UTC [556] ERROR: relation "goose_db_version" does not exist at character 3614892026-10-01 08:30:44.962 UTC [556] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14902026/10/01 08:30:44 OK 1_commit_pending_closure.sql (3.03ms)14912026/10/01 08:30:44 OK 2_object_stats_trigger.sql (1.82ms)14922026/10/01 08:30:44 OK 3_commit_push.sql (12.5ms)14932026/10/01 08:30:44 goose: up to current file version: 314942026/10/01 08:30:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14952026/10/01 08:30:44 INFO Received push request method=POST path=/api/pushes14962026/10/01 08:30:44 OK 20241026095416_initial_model.sql (10.93ms)14972026-10-01 08:30:44.989 UTC [559] ERROR: relation "goose_db_version" does not exist at character 3614982026-10-01 08:30:44.989 UTC [559] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14992026-10-01 08:30:44.990 UTC [560] ERROR: relation "goose_db_version" does not exist at character 3615002026-10-01 08:30:44.990 UTC [560] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15012026/10/01 08:30:44 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)1502--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.59s)1503=== CONT TestLeadEndsOnShutdown15042026/10/01 08:30:44 OK 20251218171726_add_pins.sql (4.34ms)15052026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)15062026/10/01 08:30:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15072026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.68ms)15082026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.74ms)15092026/10/01 08:30:45 OK 20241026095416_initial_model.sql (18.8ms)15102026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (10.31ms)15112026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000015122026/10/01 08:30:45 OK 20241026095416_initial_model.sql (19.42ms)15132026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)1514--- PASS: TestReadProxyNarinfo (0.54s)1515=== CONT TestLeadElectsOneAndHandsOver15162026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)15172026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.71ms)15182026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.51ms)15192026/10/01 08:30:45 OK 2_object_stats_trigger.sql (2.24ms)15202026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.73ms)15212026/10/01 08:30:45 OK 3_commit_push.sql (1.38ms)15222026/10/01 08:30:45 goose: up to current file version: 315232026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)15242026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)15252026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.52ms)15262026/10/01 08:30:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTg3ZjZhOTYtZmEwNi00OTMyLWJkZjEtZWU1MDg1NjVhMDdkLjYxMjBlZmU1LTUyZDItNDMzMy04ODc2LTY1OGY3N2RjYzBmZHgxNzkwODQzNDQ0NTIzMTIwNDYz parts=1215272026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.19ms)15282026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.74ms)1529--- PASS: TestRedundantMultipartUpload (0.97s)1530=== CONT TestResolveDBConnectionString1531=== RUN TestResolveDBConnectionString/flag_wins1532=== PAUSE TestResolveDBConnectionString/flag_wins1533=== RUN TestResolveDBConnectionString/file_when_flag_empty1534=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1535=== RUN TestResolveDBConnectionString/missing_file_is_an_error1536=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1537=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1538=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1539=== RUN TestResolveDBConnectionString/nothing_configured1540=== PAUSE TestResolveDBConnectionString/nothing_configured1541=== CONT TestCreatePendingClosureRejectsOversizedNAR15422026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures1543--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1544=== CONT TestClientFallsBackToClosures15452026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.35ms)15462026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000015472026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.14ms)15482026-10-01 08:30:45.034 UTC [565] ERROR: relation "goose_db_version" does not exist at character 3615492026-10-01 08:30:45.034 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15502026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.29ms)15512026/10/01 08:30:45 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2509608029/001/proxy.sock15522026/10/01 08:30:45 INFO Starting HTTP server address=127.0.0.1:4615715532026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (3.05ms)15542026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000015552026/10/01 08:30:45 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15562026/10/01 08:30:45 INFO Shutdown signal received, draining in-flight requests timeout=10s15572026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.81ms)1558--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.56s)1559=== CONT TestCacheConfigHandlerMaxNarSize15602026-10-01 08:30:45.038 UTC [566] ERROR: relation "goose_db_version" does not exist at character 3615612026-10-01 08:30:45.038 UTC [566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1562--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1563=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT15642026/10/01 08:30:45 OK 3_commit_push.sql (1.51ms)15652026/10/01 08:30:45 goose: up to current file version: 315662026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.94ms)15672026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.32ms)15682026/10/01 08:30:45 OK 3_commit_push.sql (1.37ms)15692026/10/01 08:30:45 goose: up to current file version: 315702026/10/01 08:30:45 INFO Aborted multipart uploads count=015712026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.84ms)15722026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period15732026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures15742026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)15752026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.35ms)15762026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2ms)15772026/10/01 08:30:45 OK 20251218171726_add_pins.sql (7.95ms)15782026/10/01 08:30:45 OK 20251218171726_add_pins.sql (10.55ms)15792026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)15802026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)15812026/10/01 08:30:45 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=015822026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.22ms)15832026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.29ms)15842026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.49ms)15852026-10-01 08:30:45.074 UTC [571] ERROR: relation "goose_db_version" does not exist at character 3615862026-10-01 08:30:45.074 UTC [571] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15872026/10/01 08:30:45 INFO Vacuumed table table=pending_closures15882026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.65ms)15892026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.28ms)15902026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000015912026/10/01 08:30:45 INFO Vacuumed table table=pending_objects15922026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures15932026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.27ms)15942026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000015952026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.25ms)15962026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads15972026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.27ms)15982026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.76ms)15992026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.68ms)16002026/10/01 08:30:45 OK 3_commit_push.sql (1.63ms)16012026/10/01 08:30:45 goose: up to current file version: 316022026/10/01 08:30:45 INFO Vacuumed table table=closures16032026/10/01 08:30:45 OK 3_commit_push.sql (1.09ms)16042026/10/01 08:30:45 goose: up to current file version: 316052026/10/01 08:30:45 INFO Vacuumed table table=objects16062026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/2/complete16072026/10/01 08:30:45 OK 20241026095416_initial_model.sql (8.51ms)1608--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.03s)1609=== CONT TestClientPushesUseOnePush16102026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)16112026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.23ms)16122026-10-01 08:30:45.095 UTC [572] ERROR: relation "goose_db_version" does not exist at character 3616132026-10-01 08:30:45.095 UTC [572] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16142026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)16152026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.4ms)16162026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.54ms)16172026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.3ms)16182026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000016192026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.55ms)16202026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.39ms)16212026/10/01 08:30:45 OK 3_commit_push.sql (767.13µs)16222026/10/01 08:30:45 goose: up to current file version: 316232026-10-01 08:30:45.110 UTC [575] ERROR: relation "goose_db_version" does not exist at character 3616242026-10-01 08:30:45.110 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16252026-10-01 08:30:45.111 UTC [576] ERROR: relation "goose_db_version" does not exist at character 3616262026-10-01 08:30:45.111 UTC [576] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16272026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.07ms)16282026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)16292026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.29ms)16302026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)16312026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.16ms)16322026/10/01 08:30:45 OK 20241026095416_initial_model.sql (8.89ms)16332026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.59ms)16342026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.45ms)16352026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)16362026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.97ms)16372026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000016382026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)16392026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.91ms)16402026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.17ms)16412026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.23ms)16422026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.16ms)16432026/10/01 08:30:45 OK 3_commit_push.sql (1.2ms)16442026/10/01 08:30:45 goose: up to current file version: 316452026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)16462026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)16472026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.89ms)16482026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.53ms)16492026/10/01 08:30:45 INFO Aborted multipart uploads count=016502026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.07ms)16512026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (1.8ms)16522026/10/01 08:30:45 INFO Aborted multipart uploads count=016532026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.82ms)16542026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000016552026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period16562026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.48ms)16572026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000016582026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period16592026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.12ms)16602026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.04ms)16612026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.81ms)16622026/10/01 08:30:45 OK 2_object_stats_trigger.sql (938.33µs)16632026/10/01 08:30:45 OK 3_commit_push.sql (739.21µs)16642026/10/01 08:30:45 goose: up to current file version: 316652026/10/01 08:30:45 OK 3_commit_push.sql (668.61µs)16662026/10/01 08:30:45 goose: up to current file version: 316672026/10/01 08:30:45 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16682026/10/01 08:30:45 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1669--- PASS: TestFailedS3DeleteKeepsTombstone (0.57s)1670=== CONT TestGenerateLandingPage1671--- PASS: TestGenerateLandingPage (0.00s)1672=== CONT TestService_verifyS3Integrity16732026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures16742026/10/01 08:30:45 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=016752026/10/01 08:30:45 INFO Vacuumed table table=pending_closures16762026/10/01 08:30:45 INFO Vacuumed table table=pending_objects16772026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads1678--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.44s)1679=== CONT TestService_readinessHandler16802026/10/01 08:30:45 INFO Vacuumed table table=closures16812026-10-01 08:30:45.159 UTC [579] ERROR: relation "goose_db_version" does not exist at character 3616822026-10-01 08:30:45.159 UTC [579] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16832026/10/01 08:30:45 INFO Vacuumed table table=objects1684--- PASS: TestGCSweepDeliversEachKeyOnce (0.48s)1685=== CONT TestPinProtectsFromGC16862026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures16872026/10/01 08:30:45 OK 20241026095416_initial_model.sql (15.54ms)16882026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)16892026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.41ms)16902026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)16912026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures16922026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.46ms)16932026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.64ms)16942026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.14ms)16952026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000016962026/10/01 08:30:45 INFO Aborted multipart uploads count=016972026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.28ms)16982026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.66ms)16992026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period17002026/10/01 08:30:45 OK 3_commit_push.sql (1.08ms)17012026/10/01 08:30:45 goose: up to current file version: 317022026/10/01 08:30:45 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=017032026/10/01 08:30:45 INFO Vacuumed table table=pending_closures17042026/10/01 08:30:45 INFO Vacuumed table table=pending_objects17052026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads17062026/10/01 08:30:45 INFO Vacuumed table table=closures17072026/10/01 08:30:45 INFO Vacuumed table table=objects17082026/10/01 08:30:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17092026/10/01 08:30:45 WARN Refused reserved pin name=worker-x86_64-linux17102026/10/01 08:30:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1711--- PASS: TestGCSweepSkipsPendingObjects (0.45s)17122026/10/01 08:30:45 INFO Received create pin request method=POST path=/api/pins/my-app1713=== CONT TestService_healthCheckHandler17142026/10/01 08:30:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1715--- PASS: TestCreatePin_ReservedPins (0.64s)1716=== CONT TestClientSharedPathCommittedMidPush17172026-10-01 08:30:45.227 UTC [589] ERROR: relation "goose_db_version" does not exist at character 3617182026-10-01 08:30:45.227 UTC [589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17192026-10-01 08:30:45.233 UTC [592] ERROR: relation "goose_db_version" does not exist at character 3617202026-10-01 08:30:45.233 UTC [592] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1721--- PASS: TestObjectStatsTrigger (0.46s)1722=== CONT TestGCTaskStore_ConflictDifferentParams1723--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1724=== CONT TestGCTaskStore_DeduplicateSameParams1725--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1726=== CONT TestClientWithDependencies17272026/10/01 08:30:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17282026-10-01 08:30:45.242 UTC [593] ERROR: relation "goose_db_version" does not exist at character 3617292026-10-01 08:30:45.242 UTC [593] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17302026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.08ms)17312026/10/01 08:30:45 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1732--- PASS: TestCompleteMultipartUnregistered (0.41s)1733=== CONT TestGracefulShutdownDrainsInflight17342026/10/01 08:30:45 INFO Starting HTTP server address=127.0.0.1:4566717352026/10/01 08:30:45 INFO Shutdown signal received, draining in-flight requests timeout=10s17362026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)17372026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3ms)17382026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.08ms)17392026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)17402026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.43ms)17412026/10/01 08:30:45 OK 20251218171726_add_pins.sql (9.33ms)17422026/10/01 08:30:45 OK 20260905000000_add_claims.sql (10.44ms)17432026/10/01 08:30:45 OK 20241026095416_initial_model.sql (14.6ms)17442026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)17452026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)17462026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.69ms)17472026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures17482026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.44ms)17492026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.76ms)17502026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000017512026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.48ms)17522026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.76ms)17532026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)17542026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.48ms)1755--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1756=== CONT TestGCTaskStore_StartNew1757--- PASS: TestGCTaskStore_StartNew (0.00s)1758=== CONT TestGCTaskStore_Fail1759--- PASS: TestGCTaskStore_Fail (0.00s)1760=== CONT TestPushWaitsForSweepHoldingRow17612026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.55ms)17622026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.1ms)17632026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000017642026/10/01 08:30:45 OK 3_commit_push.sql (1.36ms)17652026/10/01 08:30:45 goose: up to current file version: 317662026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.58ms)17672026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.12ms)17682026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.27ms)17692026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.38ms)17702026/10/01 08:30:45 OK 3_commit_push.sql (944.05µs)17712026/10/01 08:30:45 goose: up to current file version: 317722026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.96ms)17732026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000017742026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.98ms)17752026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.43ms)17762026/10/01 08:30:45 OK 3_commit_push.sql (1.12ms)17772026/10/01 08:30:45 goose: up to current file version: 31778--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.62s)1779=== CONT TestGCTaskStore_PhaseUpdates1780--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1781=== CONT TestSweepRechecksPendingAfterLocking17822026-10-01 08:30:45.299 UTC [599] ERROR: relation "goose_db_version" does not exist at character 3617832026-10-01 08:30:45.299 UTC [599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17842026-10-01 08:30:45.299 UTC [600] ERROR: relation "goose_db_version" does not exist at character 3617852026-10-01 08:30:45.299 UTC [600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17862026/10/01 08:30:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17872026/10/01 08:30:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1788--- PASS: TestService_NativeMTLS (0.42s)1789=== CONT TestGCTaskStore_CompletedAllowsNewTask1790--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1791=== CONT TestGetExistingObjectsLocksRows17922026/10/01 08:30:45 INFO Received cleanup request method=DELETE path=/api/pending_closures17932026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures17942026/10/01 08:30:45 INFO Aborted multipart uploads count=11795--- PASS: TestMultipartCleanup (0.53s)1796=== CONT TestGCTaskStore_GetReturnsLatest1797--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1798=== CONT TestRegisterCompletedObjectNeedsPendingRow1799--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1800=== CONT TestGCTaskStore_GetEmpty1801--- PASS: TestGCTaskStore_GetEmpty (0.00s)1802=== CONT TestProxyWriteTimeout1803=== RUN TestProxyWriteTimeout/narinfo1804=== PAUSE TestProxyWriteTimeout/narinfo1805=== RUN TestProxyWriteTimeout/1_GiB_nar1806=== PAUSE TestProxyWriteTimeout/1_GiB_nar1807=== RUN TestProxyWriteTimeout/10_GiB_nar1808=== PAUSE TestProxyWriteTimeout/10_GiB_nar1809=== RUN TestProxyWriteTimeout/unknown_size1810=== PAUSE TestProxyWriteTimeout/unknown_size1811=== CONT TestSweepSkipsRowsLockedByPush18122026-10-01 08:30:45.316 UTC [604] ERROR: relation "goose_db_version" does not exist at character 3618132026-10-01 08:30:45.316 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18142026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.96ms)18152026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.88ms)18162026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)18172026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)18182026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.42ms)18192026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.4ms)18202026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (9.9ms)18212026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (10.5ms)18222026/10/01 08:30:45 OK 20241026095416_initial_model.sql (12.49ms)18232026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)18242026/10/01 08:30:45 OK 20260905000000_add_claims.sql (4.15ms)18252026/10/01 08:30:45 OK 20260905000000_add_claims.sql (4.12ms)18262026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.76ms)18272026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.91ms)18282026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.61ms)18292026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.56ms)18302026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000018312026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.3ms)18322026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000018332026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)18342026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.79ms)1835--- PASS: TestMetricsInventory (0.44s)1836=== CONT TestService_ReadScope_PublicByDefault18372026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.8ms)18382026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.83ms)18392026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.91ms)18402026/10/01 08:30:45 OK 20260905000000_add_claims.sql (4.02ms)18412026/10/01 08:30:45 OK 3_commit_push.sql (1.8ms)18422026/10/01 08:30:45 goose: up to current file version: 318432026/10/01 08:30:45 OK 3_commit_push.sql (1.85ms)18442026/10/01 08:30:45 goose: up to current file version: 318452026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.63ms)18462026-10-01 08:30:45.353 UTC [610] ERROR: relation "goose_db_version" does not exist at character 3618472026-10-01 08:30:45.353 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18482026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.45ms)18492026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000018502026/10/01 08:30:45 INFO Aborted multipart uploads count=018512026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.97ms)18522026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.5ms)18532026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period18542026/10/01 08:30:45 OK 3_commit_push.sql (1.47ms)18552026/10/01 08:30:45 goose: up to current file version: 318562026/10/01 08:30:45 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=018572026/10/01 08:30:45 INFO Vacuumed table table=pending_closures18582026/10/01 08:30:45 INFO Vacuumed table table=pending_objects18592026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads18602026/10/01 08:30:45 INFO Vacuumed table table=closures18612026/10/01 08:30:45 INFO Vacuumed table table=objects18622026-10-01 08:30:45.365 UTC [613] ERROR: relation "goose_db_version" does not exist at character 3618632026-10-01 08:30:45.365 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1864--- PASS: TestGCMetrics (0.47s)1865=== CONT TestClientIntegration18662026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.93ms)18672026/10/01 08:30:45 INFO Aborted multipart uploads count=018682026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (8.37ms)18692026-10-01 08:30:45.380 UTC [616] ERROR: relation "goose_db_version" does not exist at character 3618702026-10-01 08:30:45.380 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18712026/10/01 08:30:45 OK 20251218171726_add_pins.sql (4.38ms)18722026/10/01 08:30:45 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=018732026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.43ms)18742026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)18752026/10/01 08:30:45 INFO Vacuumed table table=pending_closures18762026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)18772026/10/01 08:30:45 INFO Vacuumed table table=pending_objects18782026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads18792026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.82ms)18802026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.5ms)18812026-10-01 08:30:45.391 UTC [618] ERROR: relation "goose_db_version" does not exist at character 3618822026-10-01 08:30:45.391 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18832026-10-01 08:30:45.391 UTC [619] ERROR: relation "goose_db_version" does not exist at character 3618842026-10-01 08:30:45.391 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026/10/01 08:30:45 INFO Vacuumed table table=closures18862026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.08ms)18872026/10/01 08:30:45 INFO Vacuumed table table=objects18882026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)18892026/10/01 08:30:45 OK 20241026095416_initial_model.sql (9.58ms)18902026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.92ms)18912026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000018922026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.1ms)18932026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)18942026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.58ms)18952026/10/01 08:30:45 INFO Aborted multipart uploads count=018962026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period18972026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.43ms)18982026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.43ms)18992026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.58ms)19002026/10/01 08:30:45 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=019012026/10/01 08:30:45 OK 3_commit_push.sql (1.93ms)19022026/10/01 08:30:45 goose: up to current file version: 319032026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.1ms)19042026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000019052026/10/01 08:30:45 INFO Vacuumed table table=pending_closures19062026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.69ms)19072026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)19082026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.43ms)19092026/10/01 08:30:45 INFO Vacuumed table table=pending_objects19102026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads19112026/10/01 08:30:45 OK 3_commit_push.sql (1.35ms)19122026/10/01 08:30:45 goose: up to current file version: 319132026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.59ms)19142026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.95ms)19152026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.81ms)19162026/10/01 08:30:45 INFO Vacuumed table table=closures19172026/10/01 08:30:45 INFO Vacuumed table table=objects19182026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)19192026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)19202026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.15ms)1921--- PASS: TestPushDedupSurvivesConcurrentGC (0.56s)1922=== CONT TestCacheStatsHandler19232026/10/01 08:30:45 INFO lead: acquired remote=192.0.2.1:123419242026/10/01 08:30:45 INFO lead: released remote=192.0.2.1:12341925--- PASS: TestLeadEndsOnShutdown (0.42s)1926=== CONT TestClientCADerivations19272026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.56ms)19282026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000019292026/10/01 08:30:45 OK 20251218171726_add_pins.sql (4.08ms)19302026/10/01 08:30:45 OK 20251218171726_add_pins.sql (4.6ms)19312026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.23ms)19322026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.29ms)19332026/10/01 08:30:45 OK 3_commit_push.sql (1.55ms)19342026/10/01 08:30:45 goose: up to current file version: 319352026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)19362026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4ms)19372026-10-01 08:30:45.421 UTC [623] ERROR: relation "goose_db_version" does not exist at character 3619382026-10-01 08:30:45.421 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19392026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.73ms)19402026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.13ms)19412026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.18ms)19422026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.88ms)19432026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.4ms)19442026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000019452026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.97ms)19462026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000019472026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.85ms)19482026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.52ms)19492026/10/01 08:30:45 OK 2_object_stats_trigger.sql (2.1ms)19502026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.9ms)1951=== NAME TestNARDeduplicationMetadataUploadBug1952 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3022431087/001/store/9mqbnanzbx8zfmiml6jjq4li02sna0ly-file1.txt19532026/10/01 08:30:45 OK 3_commit_push.sql (1.3ms)19542026/10/01 08:30:45 goose: up to current file version: 319552026/10/01 08:30:45 OK 3_commit_push.sql (906.35µs)19562026/10/01 08:30:45 goose: up to current file version: 319572026/10/01 08:30:45 INFO lead: acquired remote=192.0.2.1:123419582026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.54ms)1959=== NAME TestOrphanedObjectsGC1960 orphaned_objects_gc_test.go:290: GC Test Summary:1961 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1962 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1963 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1964 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1965 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1966--- PASS: TestOrphanedObjectsGC (0.73s)1967=== CONT TestService_createPendingClosureHandler19682026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2ms)19692026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.07ms)19702026-10-01 08:30:45.445 UTC [650] ERROR: relation "goose_db_version" does not exist at character 3619712026-10-01 08:30:45.445 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19722026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)19732026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.19ms)19742026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.44ms)19752026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.49ms)19762026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000019772026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.16ms)19782026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.54ms)19792026/10/01 08:30:45 OK 3_commit_push.sql (1.3ms)19802026/10/01 08:30:45 goose: up to current file version: 319812026/10/01 08:30:45 OK 20241026095416_initial_model.sql (17.07ms)19822026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)19832026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.37ms)19842026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)19852026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures19862026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.04ms)19872026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.17ms)19882026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.92ms)19892026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000019902026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.37ms)1991--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)1992=== CONT TestClientErrorHandling1993=== RUN TestClientErrorHandling/InvalidStorePath1994=== PAUSE TestClientErrorHandling/InvalidStorePath1995=== RUN TestClientErrorHandling/InvalidAuthToken1996=== PAUSE TestClientErrorHandling/InvalidAuthToken19972026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.57ms)1998=== RUN TestClientErrorHandling/ServerNotAvailable1999=== PAUSE TestClientErrorHandling/ServerNotAvailable2000=== CONT TestCacheConfigHandler2001=== RUN TestCacheConfigHandler/full_config,_no_issuer2002=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2003=== RUN TestCacheConfigHandler/no_cache_url_configured2004=== PAUSE TestCacheConfigHandler/no_cache_url_configured2005=== RUN TestCacheConfigHandler/no_signing_keys2006=== PAUSE TestCacheConfigHandler/no_signing_keys2007=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2008=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2009=== CONT TestService_ReadAuthMiddleware20102026-10-01 08:30:45.489 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3620112026-10-01 08:30:45.489 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20122026/10/01 08:30:45 OK 3_commit_push.sql (1.32ms)20132026/10/01 08:30:45 goose: up to current file version: 320142026-10-01 08:30:45.491 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3620152026-10-01 08:30:45.491 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20162026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.71ms)20172026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.38ms)20182026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes20192026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)20202026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)20212026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.96ms)20222026/10/01 08:30:45 OK 20251218171726_add_pins.sql (4.65ms)20232026/10/01 08:30:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20242026/10/01 08:30:45 INFO Uploading 9mqbnanzbx8zfmiml6jjq4li02sna0ly-file1.txt (160B)20252026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures20262026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)20272026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)20282026-10-01 08:30:45.518 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3620292026-10-01 08:30:45.518 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20302026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20312026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20322026/10/01 08:30:45 WARN Failed to register uploaded object key=9mqbnanzbx8zfmiml6jjq4li02sna0ly.ls error="server returned 404: 404 page not found\n"20332026/10/01 08:30:45 INFO Signed narinfos id=1 count=120342026/10/01 08:30:45 INFO Uploading 1 narinfos20352026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.39ms)20362026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.57ms)20372026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.4ms)20382026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/1/complete20392026/10/01 08:30:45 WARN Failed to register uploaded object key=9mqbnanzbx8zfmiml6jjq4li02sna0ly.narinfo error="server returned 404: 404 page not found\n"20402026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.43ms)20412026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.54ms)20422026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000020432026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.58ms)20442026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000020452026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.92ms)20462026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.02ms)20472026/10/01 08:30:45 OK 2_object_stats_trigger.sql (999.85µs)20482026/10/01 08:30:45 OK 2_object_stats_trigger.sql (747.83µs)20492026/10/01 08:30:45 OK 3_commit_push.sql (616.71µs)20502026/10/01 08:30:45 goose: up to current file version: 320512026/10/01 08:30:45 OK 3_commit_push.sql (1.22ms)20522026/10/01 08:30:45 goose: up to current file version: 320532026/10/01 08:30:45 INFO Upload complete. (59ms)2054=== NAME TestNARDeduplicationMetadataUploadBug2055 metadata_upload_test.go:54: Retrieved narinfo from S3:2056 StorePath: /build/TestNARDeduplicationMetadataUploadBug3022431087/001/store/9mqbnanzbx8zfmiml6jjq4li02sna0ly-file1.txt2057 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2058 Compression: zstd2059 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2060 NarSize: 1602061 References: 2062 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf20632026/10/01 08:30:45 WARN readiness check failed error="closed pool"2064--- PASS: TestService_readinessHandler (0.38s)2065=== CONT TestClientMultipleUploads2066=== NAME TestNARDeduplicationMetadataUploadBug2067 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)20682026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.55ms)2069 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2070 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}20712026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)20722026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.04ms)20732026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)20742026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.39ms)20752026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.3ms)20762026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.52ms)20772026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000020782026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.97ms)20792026/10/01 08:30:45 OK 2_object_stats_trigger.sql (844.85µs)20802026/10/01 08:30:45 OK 3_commit_push.sql (1.21ms)20812026/10/01 08:30:45 goose: up to current file version: 320822026-10-01 08:30:45.562 UTC [749] ERROR: relation "goose_db_version" does not exist at character 3620832026-10-01 08:30:45.562 UTC [749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2084 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3022431087/001/store/5s3pd8lljhdhpyznvrpv1c4xlymccd5p-file2.txt2085--- PASS: TestService_healthCheckHandler (0.36s)2086=== CONT TestService_AuthMiddleware_MTLSBoundSubjects20872026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.8ms)20882026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)20892026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.58ms)20902026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)20912026/10/01 08:30:45 INFO lead: released remote=192.0.2.1:123420922026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.22ms)2093--- PASS: TestGCBugBareHashReferences (0.65s)2094=== CONT TestService_RequireScope_OIDC20952026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (9.08ms)20962026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.26ms)20972026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000020982026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.36ms)20992026/10/01 08:30:45 OK 2_object_stats_trigger.sql (858.83µs)21002026/10/01 08:30:45 OK 3_commit_push.sql (1.3ms)21012026/10/01 08:30:45 goose: up to current file version: 321022026-10-01 08:30:45.610 UTC [875] ERROR: relation "goose_db_version" does not exist at character 3621032026-10-01 08:30:45.610 UTC [875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21042026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.24ms)21052026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)21062026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.41ms)2107=== NAME TestPinProtectsFromGC2108 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC315295639/001/store/055xxg7jjzhgs8i11dani72liq4cwvah-pinned-file.txt2109 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC315295639/001/store/sggila3hwgzkaxvnwykr3bw0w15va86v-unpinned-file.txt21102026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures21112026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes21122026/10/01 08:30:45 INFO lead: acquired remote=192.0.2.1:123421132026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)21142026/10/01 08:30:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21152026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures21162026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.39ms)21172026/10/01 08:30:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21182026/10/01 08:30:45 INFO Uploading xgjjr76z7f5nk5z6acxzrzrys5v83g0p-b (216B)21192026/10/01 08:30:45 INFO Uploading qb90jbrbh6bjm9fgm07akhall1sbw0gs-shared-dep (136B)21202026/10/01 08:30:45 INFO lead: released remote=192.0.2.1:12342121--- PASS: TestLeadElectsOneAndHandsOver (0.62s)2122=== CONT TestService_AuthMiddleware_MTLSProxyHeader21232026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21242026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures21252026/10/01 08:30:45 INFO Signed narinfos id=2 count=121262026/10/01 08:30:45 INFO Uploading 1 narinfos21272026/10/01 08:30:45 WARN Failed to register uploaded object key=5s3pd8lljhdhpyznvrpv1c4xlymccd5p.ls error="server returned 404: 404 page not found\n"21282026-10-01 08:30:45.645 UTC [964] ERROR: relation "goose_db_version" does not exist at character 3621292026-10-01 08:30:45.645 UTC [964] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21302026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.45ms)21312026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.55ms)21322026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000021332026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21342026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/2/complete21352026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21362026/10/01 08:30:45 WARN Failed to register uploaded object key=ngx6lry8y16r414qdi3qwg2dcmkz5f80.ls error="server returned 404: 404 page not found\n"21372026/10/01 08:30:45 WARN Failed to register uploaded object key=5s3pd8lljhdhpyznvrpv1c4xlymccd5p.narinfo error="server returned 404: 404 page not found\n"21382026/10/01 08:30:45 WARN Failed to register uploaded object key=qb90jbrbh6bjm9fgm07akhall1sbw0gs.ls error="server returned 404: 404 page not found\n"21392026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/0afzjm5vy8a5ib7v40w6x2x520ic4f3vyzrsjrd5i4g78y5853sd.nar.zst error="server returned 404: 404 page not found\n"21402026/10/01 08:30:45 WARN Failed to register uploaded object key=xgjjr76z7f5nk5z6acxzrzrys5v83g0p.ls error="server returned 404: 404 page not found\n"21412026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.71ms)21422026/10/01 08:30:45 INFO Signed narinfos id=1 count=221432026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21442026/10/01 08:30:45 INFO Signed narinfos id=2 count=221452026/10/01 08:30:45 INFO Uploading 4 narinfos21462026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.06ms)21472026/10/01 08:30:45 INFO Upload complete. (49ms)21482026/10/01 08:30:45 OK 3_commit_push.sql (654.89µs)21492026/10/01 08:30:45 goose: up to current file version: 32150=== NAME TestNARDeduplicationMetadataUploadBug2151 metadata_upload_test.go:76: Retrieved narinfo from S3:2152 StorePath: /build/TestNARDeduplicationMetadataUploadBug3022431087/001/store/5s3pd8lljhdhpyznvrpv1c4xlymccd5p-file2.txt2153 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2154 Compression: zstd2155 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2156 NarSize: 1602157 References: 2158 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21592026/10/01 08:30:45 WARN Failed to register uploaded object key=xgjjr76z7f5nk5z6acxzrzrys5v83g0p.narinfo error="server returned 404: 404 page not found\n"21602026/10/01 08:30:45 WARN Failed to register uploaded object key=qb90jbrbh6bjm9fgm07akhall1sbw0gs.narinfo error="server returned 404: 404 page not found\n"21612026/10/01 08:30:45 WARN Failed to register uploaded object key=ngx6lry8y16r414qdi3qwg2dcmkz5f80.narinfo error="server returned 404: 404 page not found\n"2162 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2163 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2164 {"version":1,"root":{"type":"regular","size":44}}21652026/10/01 08:30:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21662026/10/01 08:30:45 WARN Failed to register uploaded object key=qb90jbrbh6bjm9fgm07akhall1sbw0gs.narinfo error="server returned 404: 404 page not found\n"2167--- PASS: TestNARDeduplicationMetadataUploadBug (0.70s)2168=== CONT TestService_AuthMiddleware_OIDC21692026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.44ms)21702026/10/01 08:30:45 INFO Completed upload id=121712026/10/01 08:30:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21722026/10/01 08:30:45 INFO Completed upload id=221732026/10/01 08:30:45 INFO Upload complete. (65ms)21742026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)2175=== NAME TestClientFallsBackToClosures2176 client_pushes_test.go:112: Retrieved narinfo from S3:2177 StorePath: /build/TestClientFallsBackToClosures3464541935/001/store/qb90jbrbh6bjm9fgm07akhall1sbw0gs-shared-dep2178 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2179 Compression: zstd2180 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822181 NarSize: 1362182 References: 2183 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2184 client_pushes_test.go:112: Retrieved narinfo from S3:2185 StorePath: /build/TestClientFallsBackToClosures3464541935/001/store/ngx6lry8y16r414qdi3qwg2dcmkz5f80-a2186 URL: nar/0afzjm5vy8a5ib7v40w6x2x520ic4f3vyzrsjrd5i4g78y5853sd.nar.zst2187 Compression: zstd2188 NarHash: sha256:0afzjm5vy8a5ib7v40w6x2x520ic4f3vyzrsjrd5i4g78y5853sd2189 NarSize: 2162190 References: /build/TestClientFallsBackToClosures3464541935/001/store/qb90jbrbh6bjm9fgm07akhall1sbw0gs-shared-dep2191 CA: text:sha256:0s4q4gbv29bmf0i9zcvmzfw3y7ipxiqiagfdw09apr2pcqxq7cw621922026/10/01 08:30:45 OK 20251218171726_add_pins.sql (4.66ms)2193 client_pushes_test.go:112: Retrieved narinfo from S3:2194 StorePath: /build/TestClientFallsBackToClosures3464541935/001/store/xgjjr76z7f5nk5z6acxzrzrys5v83g0p-b2195 URL: nar/0afzjm5vy8a5ib7v40w6x2x520ic4f3vyzrsjrd5i4g78y5853sd.nar.zst2196 Compression: zstd2197 NarHash: sha256:0afzjm5vy8a5ib7v40w6x2x520ic4f3vyzrsjrd5i4g78y5853sd2198 NarSize: 2162199 References: /build/TestClientFallsBackToClosures3464541935/001/store/qb90jbrbh6bjm9fgm07akhall1sbw0gs-shared-dep2200 CA: text:sha256:0s4q4gbv29bmf0i9zcvmzfw3y7ipxiqiagfdw09apr2pcqxq7cw622012026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes22022026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (5.76ms)22032026/10/01 08:30:45 INFO Aborted multipart uploads count=02204--- PASS: TestClientFallsBackToClosures (0.64s)2205=== CONT TestIsValidCachePath/narinfo2206=== CONT TestIsValidCachePath/wrong_extension2207=== CONT TestIsValidCachePath/leading_slash2208=== CONT TestIsValidCachePath/empty2209=== CONT TestIsValidCachePath/random_path2210=== CONT TestIsValidCachePath/invalid_char_u2211=== CONT TestIsValidCachePath/short_hash2212=== CONT TestIsValidCachePath/invalid_char_e2213=== CONT TestIsValidCachePath/ls2214=== CONT TestIsValidCachePath/nar_uncompressed2215=== CONT TestIsValidCachePath/nar_bz22216=== CONT TestIsValidCachePath/nar_xz2217=== CONT TestIsValidCachePath/nar_zst2218=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2219=== CONT TestIsValidCachePath/log2220=== CONT TestIsValidCachePath/traversal_in_middle2221=== CONT TestIsValidCachePath/index.html2222=== CONT TestIsValidCachePath/nix-cache-info2223=== CONT TestIsValidCachePath/traversal_parent2224=== CONT TestIsValidCachePath/realisation2225--- PASS: TestIsValidCachePath (0.00s)2226 --- PASS: TestIsValidCachePath/narinfo (0.00s)2227 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2228 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2229 --- PASS: TestIsValidCachePath/empty (0.00s)2230 --- PASS: TestIsValidCachePath/random_path (0.00s)2231 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2232 --- PASS: TestIsValidCachePath/short_hash (0.00s)2233 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2234 --- PASS: TestIsValidCachePath/ls (0.00s)2235 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2236 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2237 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2238 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2239 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2240 --- PASS: TestIsValidCachePath/log (0.00s)2241 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2242 --- PASS: TestIsValidCachePath/index.html (0.00s)2243 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2244 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2245 --- PASS: TestIsValidCachePath/realisation (0.00s)2246=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22472026/10/01 08:30:45 INFO Received uploads request method=POST path=/2248=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22492026/10/01 08:30:45 INFO Received complete multipart upload request method=POST path=/2250=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22512026/10/01 08:30:45 INFO Received request for more parts method=POST path=/2252=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22532026/10/01 08:30:45 INFO Received uploads request method=POST path=/2254--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2255 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2256 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2257 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2258 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2259=== CONT TestParseSingleRange/none2260=== CONT TestParseSingleRange/start_past_EOF2261=== CONT TestParseSingleRange/single_byte2262=== CONT TestParseSingleRange/suffix_exceeds_size2263=== CONT TestParseSingleRange/suffix2264=== CONT TestParseSingleRange/end_clamped_to_size2265=== CONT TestParseSingleRange/open-ended2266=== CONT TestParseSingleRange/closed2267=== CONT TestParseSingleRange/malformed_end_before_start2268=== CONT TestParseSingleRange/malformed_both_empty2269=== CONT TestParseSingleRange/malformed_no_dash2270=== CONT TestParseSingleRange/multi-range_ignored2271=== CONT TestParseSingleRange/start_far_past_EOF2272=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows22732026/10/01 08:30:45 OK 20260905000000_add_claims.sql (4.35ms)22742026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period22752026/10/01 08:30:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22762026/10/01 08:30:45 INFO Uploading jd8d603f623bnjqw27dkq1mzqp0fsmiy-b (216B)22772026/10/01 08:30:45 INFO Uploading wd39s5wjddmcfrd4kfphy8858qjgbppy-shared-dep (136B)22782026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.41ms)22792026/10/01 08:30:45 WARN Failed to register uploaded object key=4w2ch96ipw18b0dmjh0ys2xnvnaz494c.ls error="server returned 404: 404 page not found\n"22802026/10/01 08:30:45 WARN Failed to register uploaded object key=wd39s5wjddmcfrd4kfphy8858qjgbppy.ls error="server returned 404: 404 page not found\n"22812026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/119ijd2mbsiifxnj72rmi8mydvjivrqjwzv39lxwd9d6zklsyran.nar.zst error="server returned 404: 404 page not found\n"22822026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.54ms)22832026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000022842026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22852026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.5ms)22862026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.65ms)22872026/10/01 08:30:45 WARN Failed to register uploaded object key=jd8d603f623bnjqw27dkq1mzqp0fsmiy.ls error="server returned 404: 404 page not found\n"22882026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22892026/10/01 08:30:45 INFO Signed narinfos id=1 count=322902026/10/01 08:30:45 INFO Uploading 3 narinfos22912026/10/01 08:30:45 OK 3_commit_push.sql (1.82ms)22922026/10/01 08:30:45 goose: up to current file version: 322932026/10/01 08:30:45 WARN Failed to register uploaded object key=wd39s5wjddmcfrd4kfphy8858qjgbppy.narinfo error="server returned 404: 404 page not found\n"22942026/10/01 08:30:45 WARN Failed to register uploaded object key=jd8d603f623bnjqw27dkq1mzqp0fsmiy.narinfo error="server returned 404: 404 page not found\n"22952026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/1/complete22962026/10/01 08:30:45 WARN Failed to register uploaded object key=4w2ch96ipw18b0dmjh0ys2xnvnaz494c.narinfo error="server returned 404: 404 page not found\n"22972026/10/01 08:30:45 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=02298--- PASS: TestGetExistingObjectsLocksRows (0.40s)2299=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check23002026/10/01 08:30:45 INFO Vacuumed table table=pending_closures23012026/10/01 08:30:45 INFO Upload complete. (66ms)23022026/10/01 08:30:45 INFO Vacuumed table table=pending_objects23032026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads23042026/10/01 08:30:45 INFO Vacuumed table table=closures2305=== NAME TestClientPushesUseOnePush2306 client_pushes_test.go:97: Retrieved narinfo from S3:2307 StorePath: /build/TestClientPushesUseOnePush3900861974/001/store/wd39s5wjddmcfrd4kfphy8858qjgbppy-shared-dep2308 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2309 Compression: zstd2310 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822311 NarSize: 1362312 References: 2313 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2314=== NAME TestClientWithDependencies2315 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3239924781/001/store/yipvp5dg43dk0l4s7y8r6md4k7mmjskf-test-script23162026/10/01 08:30:45 INFO Vacuumed table table=objects2317=== NAME TestClientPushesUseOnePush2318 client_pushes_test.go:97: Retrieved narinfo from S3:2319 StorePath: /build/TestClientPushesUseOnePush3900861974/001/store/4w2ch96ipw18b0dmjh0ys2xnvnaz494c-a2320 URL: nar/119ijd2mbsiifxnj72rmi8mydvjivrqjwzv39lxwd9d6zklsyran.nar.zst2321 Compression: zstd2322 NarHash: sha256:119ijd2mbsiifxnj72rmi8mydvjivrqjwzv39lxwd9d6zklsyran2323 NarSize: 2162324 References: /build/TestClientPushesUseOnePush3900861974/001/store/wd39s5wjddmcfrd4kfphy8858qjgbppy-shared-dep2325 CA: text:sha256:177y11bmz24z2sr0q50r416vnj4ifcyf70z6fdad069shw56bwvq2326--- PASS: TestSweepRechecksPendingAfterLocking (0.42s)2327=== CONT TestParseSingleRange/unknown_unit2328=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23292026/10/01 08:30:45 INFO Received request for more parts method=POST path=/2330--- PASS: TestParseSingleRange (0.04s)2331 --- PASS: TestParseSingleRange/none (0.00s)2332 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2333 --- PASS: TestParseSingleRange/single_byte (0.00s)2334 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2335 --- PASS: TestParseSingleRange/suffix (0.00s)2336 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2337 --- PASS: TestParseSingleRange/open-ended (0.00s)2338 --- PASS: TestParseSingleRange/closed (0.00s)2339 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2340 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2341 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2342 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2343 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2344 --- PASS: TestParseSingleRange/unknown_unit (0.00s)23452026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes2346=== NAME TestClientPushesUseOnePush2347 client_pushes_test.go:97: Retrieved narinfo from S3:2348 StorePath: /build/TestClientPushesUseOnePush3900861974/001/store/jd8d603f623bnjqw27dkq1mzqp0fsmiy-b2349 URL: nar/119ijd2mbsiifxnj72rmi8mydvjivrqjwzv39lxwd9d6zklsyran.nar.zst2350 Compression: zstd2351 NarHash: sha256:119ijd2mbsiifxnj72rmi8mydvjivrqjwzv39lxwd9d6zklsyran2352 NarSize: 2162353 References: /build/TestClientPushesUseOnePush3900861974/001/store/wd39s5wjddmcfrd4kfphy8858qjgbppy-shared-dep2354 CA: text:sha256:177y11bmz24z2sr0q50r416vnj4ifcyf70z6fdad069shw56bwvq23552026/10/01 08:30:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23562026/10/01 08:30:45 INFO Uploading 055xxg7jjzhgs8i11dani72liq4cwvah-pinned-file.txt (128B)2357--- PASS: TestClientPushesUseOnePush (0.62s)2358=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23592026/10/01 08:30:45 INFO Received complete multipart upload request method=POST path=/23602026-10-01 08:30:45.715 UTC [1098] ERROR: relation "goose_db_version" does not exist at character 3623612026-10-01 08:30:45.715 UTC [1098] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23622026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"23632026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23642026/10/01 08:30:45 WARN Failed to register uploaded object key=055xxg7jjzhgs8i11dani72liq4cwvah.ls error="server returned 404: 404 page not found\n"23652026/10/01 08:30:45 INFO Signed narinfos id=1 count=123662026/10/01 08:30:45 INFO Uploading 1 narinfos23672026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/1/complete23682026/10/01 08:30:45 WARN Failed to register uploaded object key=055xxg7jjzhgs8i11dani72liq4cwvah.narinfo error="server returned 404: 404 page not found\n"23692026/10/01 08:30:45 INFO Upload complete. (59ms)23702026/10/01 08:30:45 INFO Aborted multipart uploads count=023712026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period2372=== NAME TestClientWithDependencies2373 client_integration_test.go:615: Found 1 dependencies (including self)2374--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.42s)2375=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23762026/10/01 08:30:45 INFO Received uploads request method=POST path=/23772026/10/01 08:30:45 OK 20241026095416_initial_model.sql (11.28ms)23782026/10/01 08:30:45 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=023792026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)23802026/10/01 08:30:45 INFO Vacuumed table table=pending_closures23812026/10/01 08:30:45 INFO Vacuumed table table=pending_objects23822026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads23832026/10/01 08:30:45 INFO Vacuumed table table=closures23842026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.56ms)23852026/10/01 08:30:45 INFO Vacuumed table table=objects23862026/10/01 08:30:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37373/oidc23872026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes2388=== CONT TestPush_RejectsBadRequests/no_objects23892026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes2390=== CONT TestPush_RejectsBadRequests/root_not_in_objects23912026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes2392=== CONT TestPush_RejectsBadRequests/no_roots23932026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes2394=== CONT TestPush_RejectsBadRequests/bad_root23952026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes2396--- PASS: TestPush_RejectsBadRequests (0.72s)2397 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2398 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2399 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2400 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2401=== CONT TestIsValidUploadKey/narinfo2402=== CONT TestIsValidUploadKey/realisation_plus_in_output2403=== CONT TestIsValidUploadKey/unknown_type2404=== CONT TestIsValidUploadKey/empty_key2405=== CONT TestIsValidUploadKey/absolute2406=== CONT TestIsValidUploadKey/traversal_nar2407=== CONT TestIsValidUploadKey/traversal2408=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2409=== CONT TestIsValidUploadKey/build_log_home-manager_file2410=== CONT TestIsValidUploadKey/realisation2411=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2412=== CONT TestIsValidUploadKey/build_log_equals2413=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2414=== CONT TestIsValidUploadKey/build_log_question_mark2415=== CONT TestIsValidUploadKey/index.html2416=== CONT TestIsValidUploadKey/build_log_plus_in_name2417=== CONT TestIsValidUploadKey/nix-cache-info2418=== CONT TestIsValidUploadKey/nar_xz2419=== CONT TestIsValidUploadKey/nar_zst2420=== CONT TestIsValidUploadKey/build_log2421=== CONT TestIsValidUploadKey/listing2422=== CONT TestIsValidUploadKey/nar_plain2423--- PASS: TestIsValidUploadKey (0.00s)2424 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2425 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2426 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2427 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2428 --- PASS: TestIsValidUploadKey/absolute (0.00s)2429 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2430 --- PASS: TestIsValidUploadKey/traversal (0.00s)2431 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2432 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2433 --- PASS: TestIsValidUploadKey/realisation (0.00s)2434 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2435 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2436 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2437 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2438 --- PASS: TestIsValidUploadKey/index.html (0.00s)2439 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2440 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2441 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2442 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2443 --- PASS: TestIsValidUploadKey/build_log (0.00s)2444 --- PASS: TestIsValidUploadKey/listing (0.00s)2445 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2446=== CONT TestServerTLSConfig/no_client_CA2447=== CONT TestServerTLSConfig/not_a_PEM_file2448=== CONT TestServerTLSConfig/missing_CA_file2449--- PASS: TestServerTLSConfig (0.00s)2450 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2451 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2452 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2453=== CONT TestResolveDBConnectionString/flag_wins2454=== CONT TestResolveDBConnectionString/nothing_configured2455=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2456=== CONT TestResolveDBConnectionString/missing_file_is_an_error2457=== CONT TestResolveDBConnectionString/file_when_flag_empty2458--- PASS: TestResolveDBConnectionString (0.00s)2459 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2460 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2461 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2462 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2463 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2464=== CONT TestProxyWriteTimeout/narinfo2465=== CONT TestProxyWriteTimeout/10_GiB_nar2466=== CONT TestProxyWriteTimeout/1_GiB_nar2467=== CONT TestProxyWriteTimeout/unknown_size2468--- PASS: TestProxyWriteTimeout (0.00s)2469 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2470 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2471 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2472 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2473=== CONT TestClientErrorHandling/InvalidStorePath24742026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (9.65ms)24752026/10/01 08:30:45 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)24762026/10/01 08:30:45 INFO Uploading fx989wd6xv6yk12c75fw336xp4q9kxwb-shared-dep (136B)24772026/10/01 08:30:45 INFO Uploading vjmw2jz0fplgsyx7z66m8mnz1w24iwps-top (224B)24782026/10/01 08:30:45 INFO Aborted multipart uploads count=02479--- PASS: TestService_ReadScope_PublicByDefault (0.41s)2480=== CONT TestClientErrorHandling/ServerNotAvailable24812026-10-01 08:30:45.753 UTC [1140] ERROR: relation "goose_db_version" does not exist at character 3624822026-10-01 08:30:45.753 UTC [1140] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24832026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period24842026/10/01 08:30:45 OK 20260905000000_add_claims.sql (4.27ms)24852026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.4ms)24862026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/0lm6qj7a5m1yw31dpsv0dshq3wz058mcc88zxyibkijdcg8h8ai9.nar.zst error="server returned 404: 404 page not found\n"24872026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24882026/10/01 08:30:45 WARN Failed to register uploaded object key=fx989wd6xv6yk12c75fw336xp4q9kxwb.ls error="server returned 404: 404 page not found\n"24892026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24902026/10/01 08:30:45 WARN Failed to register uploaded object key=vjmw2jz0fplgsyx7z66m8mnz1w24iwps.ls error="server returned 404: 404 page not found\n"24912026/10/01 08:30:45 INFO Signed narinfos id=1 count=224922026/10/01 08:30:45 INFO Uploading 2 narinfos24932026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.72ms)24942026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000024952026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.11ms)24962026/10/01 08:30:45 WARN Failed to register uploaded object key=fx989wd6xv6yk12c75fw336xp4q9kxwb.narinfo error="server returned 404: 404 page not found\n"24972026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/1/complete24982026/10/01 08:30:45 WARN Failed to register uploaded object key=vjmw2jz0fplgsyx7z66m8mnz1w24iwps.narinfo error="server returned 404: 404 page not found\n"24992026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.4ms)25002026/10/01 08:30:45 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=025012026/10/01 08:30:45 OK 3_commit_push.sql (1.81ms)25022026/10/01 08:30:45 goose: up to current file version: 325032026/10/01 08:30:45 INFO Vacuumed table table=pending_closures25042026/10/01 08:30:45 INFO Vacuumed table table=pending_objects2505=== CONT TestClientErrorHandling/InvalidAuthToken25062026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads25072026/10/01 08:30:45 INFO Vacuumed table table=closures25082026-10-01 08:30:45.767 UTC [1178] ERROR: relation "goose_db_version" does not exist at character 3625092026-10-01 08:30:45.767 UTC [1178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25102026/10/01 08:30:45 INFO Upload complete. (65ms)25112026/10/01 08:30:45 INFO Vacuumed table table=objects2512=== NAME TestClientSharedPathCommittedMidPush2513 client_integration_test.go:680: Retrieved narinfo from S3:2514 StorePath: /build/TestClientSharedPathCommittedMidPush1842341325/001/store/fx989wd6xv6yk12c75fw336xp4q9kxwb-shared-dep2515 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2516 Compression: zstd2517 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822518 NarSize: 1362519 References: 2520 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n25212026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.44ms)2522--- PASS: TestSweepSkipsRowsLockedByPush (0.46s)2523=== CONT TestCacheConfigHandler/full_config,_no_issuer2524=== CONT TestCacheConfigHandler/no_signing_keys2525=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2526=== CONT TestCacheConfigHandler/no_cache_url_configured2527--- PASS: TestCacheConfigHandler (0.00s)2528 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2529 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2530 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2531 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2532=== NAME TestClientSharedPathCommittedMidPush2533 client_integration_test.go:680: Retrieved narinfo from S3:2534 StorePath: /build/TestClientSharedPathCommittedMidPush1842341325/001/store/vjmw2jz0fplgsyx7z66m8mnz1w24iwps-top2535 URL: nar/0lm6qj7a5m1yw31dpsv0dshq3wz058mcc88zxyibkijdcg8h8ai9.nar.zst2536 Compression: zstd2537 NarHash: sha256:0lm6qj7a5m1yw31dpsv0dshq3wz058mcc88zxyibkijdcg8h8ai92538 NarSize: 2242539 References: /build/TestClientSharedPathCommittedMidPush1842341325/001/store/fx989wd6xv6yk12c75fw336xp4q9kxwb-shared-dep2540 CA: text:sha256:132cq3i8rwccd1l702k1w7fq787n2k6vdq0y21kj0bk136jmywav25412026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)2542--- PASS: TestClientSharedPathCommittedMidPush (0.56s)25432026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.9ms)25442026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)25452026/10/01 08:30:45 OK 20241026095416_initial_model.sql (12.66ms)25462026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)25472026/10/01 08:30:45 OK 20260905000000_add_claims.sql (5.99ms)25482026/10/01 08:30:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36587/oidc25492026/10/01 08:30:45 OK 20251218171726_add_pins.sql (4.28ms)25502026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (3.53ms)25512026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.66ms)25522026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000025532026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)25542026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.59ms)25552026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes25562026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes25572026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.81ms)25582026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.66ms)25592026/10/01 08:30:45 OK 3_commit_push.sql (1.48ms)25602026/10/01 08:30:45 goose: up to current file version: 325612026/10/01 08:30:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25622026/10/01 08:30:45 INFO Uploading sggila3hwgzkaxvnwykr3bw0w15va86v-unpinned-file.txt (128B)25632026/10/01 08:30:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25642026/10/01 08:30:45 INFO Uploading yipvp5dg43dk0l4s7y8r6md4k7mmjskf-test-script (136B)25652026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.97ms)25662026/10/01 08:30:45 WARN Failed to register uploaded object key=sggila3hwgzkaxvnwykr3bw0w15va86v.ls error="server returned 404: 404 page not found\n"25672026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.92ms)25682026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000025692026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign25702026/10/01 08:30:45 INFO Signed narinfos id=2 count=125712026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"25722026/10/01 08:30:45 INFO Uploading 1 narinfos25732026/10/01 08:30:45 WARN Failed to register uploaded object key=log/f864qy8fbrwbdlwp8iiw3man89ahfwb2-test-script.drv error="server returned 404: 404 page not found\n"25742026/10/01 08:30:45 OK 1_commit_pending_closure.sql (3.99ms)25752026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"25762026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25772026/10/01 08:30:45 WARN Failed to register uploaded object key=yipvp5dg43dk0l4s7y8r6md4k7mmjskf.ls error="server returned 404: 404 page not found\n"25782026/10/01 08:30:45 INFO Signed narinfos id=1 count=125792026/10/01 08:30:45 INFO Uploading 1 narinfos25802026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/2/complete25812026/10/01 08:30:45 WARN Failed to register uploaded object key=sggila3hwgzkaxvnwykr3bw0w15va86v.narinfo error="server returned 404: 404 page not found\n"25822026/10/01 08:30:45 OK 2_object_stats_trigger.sql (1.96ms)25832026/10/01 08:30:45 OK 3_commit_push.sql (1.33ms)25842026/10/01 08:30:45 goose: up to current file version: 325852026/10/01 08:30:45 INFO Upload complete. (53ms)25862026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/1/complete25872026/10/01 08:30:45 WARN Failed to register uploaded object key=yipvp5dg43dk0l4s7y8r6md4k7mmjskf.narinfo error="server returned 404: 404 page not found\n"2588--- PASS: TestCacheStatsHandler (0.41s)25892026-10-01 08:30:45.822 UTC [1254] ERROR: relation "goose_db_version" does not exist at character 3625902026-10-01 08:30:45.822 UTC [1254] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25912026/10/01 08:30:45 INFO Upload complete. (60ms)2592=== NAME TestClientIntegration2593 client_integration_test.go:286: Created store path: /build/TestClientIntegration1706452118/002/store/1abgxir42ahrx9daw5144w564jvcs3ic-test-file.txt25942026-10-01 08:30:45.825 UTC [1255] ERROR: relation "goose_db_version" does not exist at character 3625952026-10-01 08:30:45.825 UTC [1255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2596=== NAME TestClientWithDependencies2597 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3239924781/001/store) requires matching store prefix2598--- PASS: TestClientWithDependencies (0.59s)25992026/10/01 08:30:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete26002026/10/01 08:30:45 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/present26012026/10/01 08:30:45 OK 20241026095416_initial_model.sql (9.78ms)26022026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)26032026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.11ms)26042026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)26052026/10/01 08:30:45 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTg3ZjZhOTYtZmEwNi00OTMyLWJkZjEtZWU1MDg1NjVhMDdkLjNmNDU4YjJiLTk1MjctNGMzMS1iNzY1LTA1Y2FkMDViMDIyN3gxNzkwODQzNDQ1NTIzMjA4NDQ4 parts=1026062026/10/01 08:30:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete26072026-10-01 08:30:45.848 UTC [1275] ERROR: relation "goose_db_version" does not exist at character 3626082026-10-01 08:30:45.848 UTC [1275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26092026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.89ms)26102026/10/01 08:30:45 INFO Completed upload id=126112026/10/01 08:30:45 OK 20241026095416_initial_model.sql (12.48ms)26122026/10/01 08:30:45 INFO Received create pin request method=POST path=/api/pins/myapp26132026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures26142026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)26152026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.74ms)26162026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures26172026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures26182026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures26192026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (2.76ms)26202026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000026212026/10/01 08:30:45 OK 20251218171726_add_pins.sql (3.81ms)26222026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures26232026/10/01 08:30:45 OK 1_commit_pending_closure.sql (2.59ms)26242026/10/01 08:30:45 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC315295639/001/store/055xxg7jjzhgs8i11dani72liq4cwvah-pinned-file.txt narinfo_key=055xxg7jjzhgs8i11dani72liq4cwvah.narinfo26252026/10/01 08:30:45 OK 2_object_stats_trigger.sql (892.15µs)26262026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)26272026/10/01 08:30:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures26282026/10/01 08:30:45 OK 3_commit_push.sql (919.23µs)26292026/10/01 08:30:45 goose: up to current file version: 326302026/10/01 08:30:45 INFO Garbage collection started26312026/10/01 08:30:45 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo26322026/10/01 08:30:45 WARN Found objects in DB but missing from S3, will re-upload count=12633--- PASS: TestService_verifyS3Integrity (0.71s)26342026/10/01 08:30:45 OK 20260905000000_add_claims.sql (3.52ms)26352026/10/01 08:30:45 OK 20241026095416_initial_model.sql (10.58ms)26362026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.33ms)26372026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)26382026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.65ms)26392026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000026402026/10/01 08:30:45 INFO Aborted multipart uploads count=026412026/10/01 08:30:45 OK 20251218171726_add_pins.sql (2.7ms)26422026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.78ms)26432026/10/01 08:30:45 OK 2_object_stats_trigger.sql (859.43µs)26442026/10/01 08:30:45 OK 3_commit_push.sql (858.95µs)26452026/10/01 08:30:45 goose: up to current file version: 326462026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period26472026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)2648--- PASS: TestService_ReadAuthMiddleware (0.38s)26492026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.43ms)26502026-10-01 08:30:45.875 UTC [1328] ERROR: relation "goose_db_version" does not exist at character 3626512026-10-01 08:30:45.875 UTC [1328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26522026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (2.05ms)26532026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.47ms)26542026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000026552026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.69ms)26562026/10/01 08:30:45 OK 2_object_stats_trigger.sql (734.53µs)26572026/10/01 08:30:45 OK 3_commit_push.sql (570.43µs)26582026/10/01 08:30:45 goose: up to current file version: 326592026/10/01 08:30:45 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=026602026/10/01 08:30:45 INFO Vacuumed table table=pending_closures26612026/10/01 08:30:45 OK 20241026095416_initial_model.sql (9.53ms)26622026/10/01 08:30:45 INFO Vacuumed table table=pending_objects26632026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads26642026/10/01 08:30:45 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)26652026/10/01 08:30:45 INFO Vacuumed table table=closures26662026/10/01 08:30:45 INFO Vacuumed table table=objects26672026/10/01 08:30:45 OK 20251218171726_add_pins.sql (2.68ms)26682026/10/01 08:30:45 OK 20260628120000_add_object_size_and_stats.sql (2.72ms)26692026/10/01 08:30:45 INFO Received push request method=POST path=/api/pushes26702026/10/01 08:30:45 OK 20260905000000_add_claims.sql (2.22ms)26712026/10/01 08:30:45 OK 20260920000000_drop_claims.sql (1.57ms)26722026/10/01 08:30:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26732026/10/01 08:30:45 INFO Uploading 1abgxir42ahrx9daw5144w564jvcs3ic-test-file.txt (152B)26742026/10/01 08:30:45 OK 20260923120000_add_pushes.sql (1.97ms)26752026/10/01 08:30:45 goose: successfully migrated database to version: 2026092312000026762026/10/01 08:30:45 OK 1_commit_pending_closure.sql (1.68ms)26772026/10/01 08:30:45 OK 2_object_stats_trigger.sql (762.05µs)26782026/10/01 08:30:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26792026/10/01 08:30:45 WARN Failed to register uploaded object key=1abgxir42ahrx9daw5144w564jvcs3ic.ls error="server returned 404: 404 page not found\n"26802026/10/01 08:30:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"26812026/10/01 08:30:45 OK 3_commit_push.sql (1.45ms)26822026/10/01 08:30:45 goose: up to current file version: 326832026/10/01 08:30:45 INFO Signed narinfos id=1 count=126842026/10/01 08:30:45 INFO Uploading 1 narinfos26852026/10/01 08:30:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26862026/10/01 08:30:45 WARN mTLS auth: bound subjects configured but subject DN unavailable26872026/10/01 08:30:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2688--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.33s)26892026/10/01 08:30:45 INFO Received complete push request method=POST path=/api/pushes/1/complete26902026/10/01 08:30:45 WARN Failed to register uploaded object key=1abgxir42ahrx9daw5144w564jvcs3ic.narinfo error="server returned 404: 404 page not found\n"26912026/10/01 08:30:45 INFO Upload complete. (58ms)2692=== NAME TestClientCADerivations2693 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2580943130/001/store/sb6rn827zch7japncdakrwg959y5h41z-ca-test2694=== NAME TestClientMultipleUploads2695 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads51829495/001/store/r48fjhv4zgg2gcl02f49kcklz0qwxf9i-test-file-0.txt2696--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)26972026/10/01 08:30:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.914517ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2698=== NAME TestClientCADerivations2699 client_ca_test.go:139: Found 1 dependencies (including self)27002026/10/01 08:30:45 INFO All 1 paths already cached2701=== NAME TestClientIntegration2702 client_integration_test.go:312: Retrieved narinfo from S3:2703 StorePath: /build/TestClientIntegration1706452118/002/store/1abgxir42ahrx9daw5144w564jvcs3ic-test-file.txt2704 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2705 Compression: zstd2706 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12707 NarSize: 1522708 References: 2709 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12710 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2711 client_integration_test.go:313: Decompressed .ls content (64 bytes):2712 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2713 client_integration_test.go:316: Testing garbage collection...27142026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures2715=== NAME TestClientMultipleUploads2716 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads51829495/001/store/ab07nfql7gyijic0l7m345gksc09qi6q-test-file-1.txt27172026/10/01 08:30:45 INFO Aborted multipart uploads count=027182026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period27192026/10/01 08:30:45 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=027202026/10/01 08:30:45 INFO Received uploads request method=POST path=/api/pending_closures27212026/10/01 08:30:45 INFO Vacuumed table table=pending_closures27222026/10/01 08:30:45 INFO Vacuumed table table=pending_objects27232026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads27242026/10/01 08:30:45 INFO Vacuumed table table=closures27252026/10/01 08:30:45 INFO Vacuumed table table=objects27262026/10/01 08:30:45 INFO Aborted multipart uploads count=02727=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2728=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2729=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2730=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2731=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2732=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2733=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2734=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2735=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2736=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2737=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27382026/10/01 08:30:45 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]2739=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured27402026/10/01 08:30:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures27412026/10/01 08:30:45 INFO Garbage collection started27422026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period27432026/10/01 08:30:45 WARN Authentication failed token_preview=eyJhbGciOi...TkKSyBySWA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2744--- PASS: TestService_AuthMiddleware_OIDC (0.33s)2745 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2746 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2747 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2748 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)27492026/10/01 08:30:45 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=02750=== NAME TestClientMultipleUploads2751 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads51829495/001/store/8x6nd8j07rzq1h6g7jhgxyvf222nmdcj-test-file-2.txt27522026/10/01 08:30:45 INFO Vacuumed table table=pending_closures27532026/10/01 08:30:45 INFO Vacuumed table table=pending_objects27542026/10/01 08:30:45 INFO Aborted multipart uploads count=027552026/10/01 08:30:45 INFO Vacuumed table table=multipart_uploads27562026/10/01 08:30:45 INFO Vacuumed table table=closures27572026/10/01 08:30:45 INFO Vacuumed table table=objects27582026/10/01 08:30:45 WARN Force mode enabled - objects will be deleted immediately without grace period2759--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2760 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)2761 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)27622026/10/01 08:30:46 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=027632026/10/01 08:30:46 INFO Vacuumed table table=pending_closures27642026/10/01 08:30:46 INFO Vacuumed table table=pending_objects27652026/10/01 08:30:46 INFO Vacuumed table table=multipart_uploads27662026/10/01 08:30:46 INFO Vacuumed table table=closures27672026/10/01 08:30:46 INFO Vacuumed table table=objects2768=== RUN TestService_RequireScope_OIDC/builder_may_write2769=== PAUSE TestService_RequireScope_OIDC/builder_may_write2770=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2771=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2772=== RUN TestService_RequireScope_OIDC/ops_may_admin2773=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2774=== RUN TestService_RequireScope_OIDC/ops_may_not_write2775=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2776=== RUN TestService_RequireScope_OIDC/reader_may_not_write2777=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2778=== RUN TestService_RequireScope_OIDC/static_token_may_admin2779=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2780=== RUN TestService_RequireScope_OIDC/static_token_may_write2781=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2782=== RUN TestService_RequireScope_OIDC/reader_may_read2783=== PAUSE TestService_RequireScope_OIDC/reader_may_read2784=== RUN TestService_RequireScope_OIDC/writer_implies_read2785=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2786=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2787=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2788=== CONT TestService_RequireScope_OIDC/builder_may_write2789=== CONT TestService_RequireScope_OIDC/static_token_may_admin2790=== CONT TestService_RequireScope_OIDC/writer_implies_read2791=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2792=== CONT TestService_RequireScope_OIDC/ops_may_not_write2793=== CONT TestService_RequireScope_OIDC/reader_may_not_write2794=== CONT TestService_RequireScope_OIDC/ops_may_admin2795=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2796=== CONT TestService_RequireScope_OIDC/static_token_may_write2797=== CONT TestService_RequireScope_OIDC/reader_may_read2798--- PASS: TestService_RequireScope_OIDC (0.46s)2799 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2800 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2801 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2802 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2803 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2804 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2805 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2806 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2807 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2808 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)28092026/10/01 08:30:46 INFO Received push request method=POST path=/api/pushes28102026/10/01 08:30:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)28112026/10/01 08:30:46 INFO Uploading sb6rn827zch7japncdakrwg959y5h41z-ca-test (144B)28122026/10/01 08:30:46 INFO Received push request method=POST path=/api/pushes28132026/10/01 08:30:46 WARN Failed to register uploaded object key=sb6rn827zch7japncdakrwg959y5h41z.ls error="server returned 404: 404 page not found\n"28142026/10/01 08:30:46 WARN Failed to register uploaded object key=log/q81pf55lg320z0zxa4kvcr8ci78f6v3b-ca-test.drv error="server returned 404: 404 page not found\n"28152026/10/01 08:30:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28162026/10/01 08:30:46 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"28172026/10/01 08:30:46 INFO Signed narinfos id=1 count=128182026/10/01 08:30:46 INFO Uploading 1 narinfos28192026/10/01 08:30:46 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)28202026/10/01 08:30:46 INFO Uploading r48fjhv4zgg2gcl02f49kcklz0qwxf9i-test-file-0.txt (160B)28212026/10/01 08:30:46 INFO Uploading ab07nfql7gyijic0l7m345gksc09qi6q-test-file-1.txt (160B)28222026/10/01 08:30:46 INFO Uploading 8x6nd8j07rzq1h6g7jhgxyvf222nmdcj-test-file-2.txt (160B)28232026/10/01 08:30:46 INFO Received complete push request method=POST path=/api/pushes/1/complete28242026/10/01 08:30:46 WARN Failed to register uploaded object key=sb6rn827zch7japncdakrwg959y5h41z.narinfo error="server returned 404: 404 page not found\n"28252026/10/01 08:30:46 WARN Failed to register uploaded object key=r48fjhv4zgg2gcl02f49kcklz0qwxf9i.ls error="server returned 404: 404 page not found\n"28262026/10/01 08:30:46 WARN Failed to register uploaded object key=ab07nfql7gyijic0l7m345gksc09qi6q.ls error="server returned 404: 404 page not found\n"28272026/10/01 08:30:46 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"28282026/10/01 08:30:46 WARN Failed to register uploaded object key=8x6nd8j07rzq1h6g7jhgxyvf222nmdcj.ls error="server returned 404: 404 page not found\n"28292026/10/01 08:30:46 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"28302026/10/01 08:30:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28312026/10/01 08:30:46 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"28322026/10/01 08:30:46 INFO Signed narinfos id=1 count=328332026/10/01 08:30:46 INFO Uploading 3 narinfos28342026/10/01 08:30:46 INFO Upload complete. (90ms)28352026/10/01 08:30:46 WARN Failed to register uploaded object key=8x6nd8j07rzq1h6g7jhgxyvf222nmdcj.narinfo error="server returned 404: 404 page not found\n"28362026/10/01 08:30:46 WARN Failed to register uploaded object key=r48fjhv4zgg2gcl02f49kcklz0qwxf9i.narinfo error="server returned 404: 404 page not found\n"28372026/10/01 08:30:46 INFO Received complete push request method=POST path=/api/pushes/1/complete28382026/10/01 08:30:46 WARN Failed to register uploaded object key=ab07nfql7gyijic0l7m345gksc09qi6q.narinfo error="server returned 404: 404 page not found\n"2839=== NAME TestClientCADerivations2840 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2580943130/001/store/sb6rn827zch7japncdakrwg959y5h41z-ca-test2841 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2842 Compression: zstd2843 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2844 NarSize: 1442845 References: 2846 Deriver: /build/TestClientCADerivations2580943130/001/store/q81pf55lg320z0zxa4kvcr8ci78f6v3b-ca-test.drv2847 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2848 client_ca_test.go:185: Checking for realisation files in S3...2849 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2850 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache28512026/10/01 08:30:46 INFO Upload complete. (48ms)2852=== NAME TestClientMultipleUploads2853 client_integration_test.go:369: Uploaded 3 paths in 85.26532ms2854--- PASS: TestClientMultipleUploads (0.55s)28552026/10/01 08:30:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28562026/10/01 08:30:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28572026/10/01 08:30:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete28582026/10/01 08:30:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.24376ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2859--- PASS: TestPushWaitsForSweepHoldingRow (0.87s)28602026/10/01 08:30:46 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTg3ZjZhOTYtZmEwNi00OTMyLWJkZjEtZWU1MDg1NjVhMDdkLjBjMjE3Nzg0LTI3YmYtNDAzNy1hNTA3LTQ4ZjE4YjhkNzhmZXgxNzkwODQzNDQ1ODYwNDYyMjMz parts=1028612026/10/01 08:30:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete28622026/10/01 08:30:46 INFO Completed upload id=128632026/10/01 08:30:46 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000028642026/10/01 08:30:46 INFO Received uploads request method=POST path=/api/pending_closures28652026/10/01 08:30:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures2866=== NAME TestClientCADerivations2867 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2868 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2869 error: binary cache 's3://bucket67?endpoint=http://localhost:36251®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2580943130/001/store'2870 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12871--- PASS: TestClientCADerivations (0.75s)28722026/10/01 08:30:46 INFO Aborted multipart uploads count=028732026/10/01 08:30:46 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=028742026/10/01 08:30:46 INFO Vacuumed table table=pending_closures28752026/10/01 08:30:46 INFO Vacuumed table table=pending_objects28762026/10/01 08:30:46 INFO Vacuumed table table=multipart_uploads28772026/10/01 08:30:46 INFO Vacuumed table table=closures28782026/10/01 08:30:46 INFO Vacuumed table table=objects28792026/10/01 08:30:46 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002880--- PASS: TestService_createPendingClosureHandler (0.77s)2881=== NAME TestOrphanedObjectsGCStressTest2882 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2883 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion28842026/10/01 08:30:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=784.568064ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2885--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2886 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2887 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2888 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.83s)2889=== NAME TestOrphanedObjectsGCStressTest2890 orphaned_objects_gc_test.go:509: Stress test completed successfully:2891 orphaned_objects_gc_test.go:510: - Active objects preserved: 202892 orphaned_objects_gc_test.go:511: - Objects deleted: 2102893 orphaned_objects_gc_test.go:512: - Total GC'd: 2102894--- PASS: TestOrphanedObjectsGCStressTest (1.95s)28952026/10/01 08:30:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.561126204s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28962026/10/01 08:30:47 WARN Rate limiter enabled after throttle name=s3-test rate=528972026/10/01 08:30:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2898=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2899 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102900 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002901--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.48s)29022026/10/01 08:30:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02903=== NAME TestPinProtectsFromGC2904 client_integration_test.go:794: Pin successfully protected closure from garbage collection2905--- PASS: TestPinProtectsFromGC (2.70s)29062026/10/01 08:30:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02907=== NAME TestClientIntegration2908 client_integration_test.go:323: Objects in database after GC:2909 client_integration_test.go:323: Successfully deleted all objects with GC --force2910--- PASS: TestClientIntegration (2.62s)29112026/10/01 08:30:48 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-config29122026/10/01 08:30:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.191094ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29132026/10/01 08:30:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.799895ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29142026/10/01 08:30:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=851.74325ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29152026/10/01 08:30:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.457532826s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29162026/10/01 08:30:51 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"29172026/10/01 08:30:51 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-config29182026/10/01 08:30:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.706813ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29192026/10/01 08:30:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.126539ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29202026/10/01 08:30:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.0367ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29212026/10/01 08:30:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.72768099s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29222026/10/01 08:30:55 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_closures29232026/10/01 08:30:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.055483ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29242026/10/01 08:30:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.461326ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29252026/10/01 08:30:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=870.390953ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29262026/10/01 08:30:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.545631805s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2927--- PASS: TestClientErrorHandling (0.00s)2928 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2929 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2930 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.46s)2931PASS29322026-10-01 08:30:58.438 UTC [128] LOG: received smart shutdown request29332026-10-01 08:30:58.442 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 129342026-10-01 08:30:58.450 UTC [133] LOG: shutting down29352026-10-01 08:30:58.451 UTC [133] LOG: checkpoint starting: shutdown immediate29362026-10-01 08:30:59.261 UTC [133] LOG: checkpoint complete: wrote 10324 buffers (63.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 22 recycled; write=0.179 s, sync=0.606 s, total=0.811 s; sync files=26285, longest=0.002 s, average=0.001 s; distance=357670 kB, estimate=357670 kB; lsn=0/174AF558, redo lsn=0/174AF55829372026-10-01 08:30:59.334 UTC [128] LOG: database system is shut down2938Running OIDC tests...2939=== RUN TestAudienceForIssuer2940=== PAUSE TestAudienceForIssuer2941=== RUN TestGlobMatch2942=== PAUSE TestGlobMatch2943=== RUN TestValidateToken_ValidToken2944=== PAUSE TestValidateToken_ValidToken2945=== RUN TestValidateToken_WrongAudience2946=== PAUSE TestValidateToken_WrongAudience2947=== RUN TestValidateToken_Expired2948=== PAUSE TestValidateToken_Expired2949=== RUN TestValidateToken_BoundClaimsMismatch2950=== PAUSE TestValidateToken_BoundClaimsMismatch2951=== RUN TestValidateToken_BoundSubjectMismatch2952=== PAUSE TestValidateToken_BoundSubjectMismatch2953=== RUN TestValidateToken_MultipleProviders2954=== PAUSE TestValidateToken_MultipleProviders2955=== RUN TestValidateToken_NoMatchingProvider2956=== PAUSE TestValidateToken_NoMatchingProvider2957=== RUN TestValidateToken_KubernetesServiceAccount2958=== PAUSE TestValidateToken_KubernetesServiceAccount2959=== RUN TestNewValidator_KubernetesRequiresCA2960=== PAUSE TestNewValidator_KubernetesRequiresCA2961=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2962=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2963=== RUN TestPins_ReservedForMatchingRule2964=== PAUSE TestPins_ReservedForMatchingRule2965=== RUN TestPins_TopLevelShorthand2966=== PAUSE TestPins_TopLevelShorthand2967=== RUN TestPins_ConfigValidation2968=== PAUSE TestPins_ConfigValidation2969=== RUN TestScopes_LegacyProviderDefaultsToWrite2970=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2971=== RUN TestScopes_Rules2972=== PAUSE TestScopes_Rules2973=== RUN TestScopes_ConfigValidation2974=== PAUSE TestScopes_ConfigValidation2975=== CONT TestAudienceForIssuer2976=== CONT TestValidateToken_BoundClaimsMismatch2977--- PASS: TestAudienceForIssuer (0.00s)2978=== CONT TestValidateToken_ValidToken2979=== CONT TestValidateToken_KubernetesServiceAccount2980=== CONT TestValidateToken_NoMatchingProvider2981=== CONT TestNewValidator_KubernetesRequiresCA2982=== CONT TestScopes_LegacyProviderDefaultsToWrite2983=== CONT TestValidateToken_WrongAudience2984=== CONT TestValidateToken_Expired2985=== CONT TestGlobMatch2986=== RUN TestGlobMatch/foo_foo2987=== PAUSE TestGlobMatch/foo_foo2988=== RUN TestGlobMatch/foo_bar2989=== PAUSE TestGlobMatch/foo_bar2990=== RUN TestGlobMatch/*_2991=== PAUSE TestGlobMatch/*_2992=== RUN TestGlobMatch/*_anything2993=== PAUSE TestGlobMatch/*_anything2994=== CONT TestValidateToken_MultipleProviders2995=== CONT TestValidateToken_BoundSubjectMismatch2996=== CONT TestPins_ConfigValidation2997=== CONT TestScopes_ConfigValidation2998=== CONT TestScopes_Rules2999=== CONT TestPins_ReservedForMatchingRule3000=== CONT TestPins_TopLevelShorthand3001=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3002=== RUN TestGlobMatch/foo*_foo3003=== PAUSE TestGlobMatch/foo*_foo3004=== RUN TestGlobMatch/foo*_foobar3005=== PAUSE TestGlobMatch/foo*_foobar3006=== RUN TestGlobMatch/foo*_bar3007=== PAUSE TestGlobMatch/foo*_bar3008=== RUN TestGlobMatch/*bar_bar3009=== PAUSE TestGlobMatch/*bar_bar3010=== RUN TestGlobMatch/*bar_foobar3011=== PAUSE TestGlobMatch/*bar_foobar3012=== RUN TestGlobMatch/*bar_foo3013=== PAUSE TestGlobMatch/*bar_foo3014=== RUN TestGlobMatch/foo*bar_foobar3015=== PAUSE TestGlobMatch/foo*bar_foobar3016=== RUN TestGlobMatch/foo*bar_foo123bar3017=== PAUSE TestGlobMatch/foo*bar_foo123bar3018=== RUN TestGlobMatch/foo*bar_foobarbaz3019=== PAUSE TestGlobMatch/foo*bar_foobarbaz3020=== RUN TestGlobMatch/*/*_foo/bar3021=== PAUSE TestGlobMatch/*/*_foo/bar3022=== RUN TestGlobMatch/*/*_foo3023=== PAUSE TestGlobMatch/*/*_foo3024=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3025=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3026=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03027=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03028=== RUN TestGlobMatch/refs/*/main_refs/heads/main3029=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3030=== RUN TestGlobMatch/fo?_foo3031=== PAUSE TestGlobMatch/fo?_foo3032=== RUN TestGlobMatch/fo?_fo3033=== PAUSE TestGlobMatch/fo?_fo3034=== RUN TestGlobMatch/fo?_fooo3035=== PAUSE TestGlobMatch/fo?_fooo3036=== RUN TestGlobMatch/?oo_foo3037=== PAUSE TestGlobMatch/?oo_foo3038=== RUN TestGlobMatch/?oo_boo3039=== PAUSE TestGlobMatch/?oo_boo3040=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3041=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3042=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3043=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3044=== CONT TestGlobMatch/foo_foo3045=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3046=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3047=== CONT TestGlobMatch/?oo_boo3048=== CONT TestGlobMatch/?oo_foo3049=== CONT TestGlobMatch/fo?_fooo3050=== CONT TestGlobMatch/fo?_fo3051=== CONT TestGlobMatch/fo?_foo3052=== CONT TestGlobMatch/refs/*/main_refs/heads/main3053=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03054=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3055=== CONT TestGlobMatch/*/*_foo3056=== CONT TestGlobMatch/*/*_foo/bar3057=== CONT TestGlobMatch/foo*bar_foobarbaz3058=== CONT TestGlobMatch/foo*bar_foo123bar3059=== CONT TestGlobMatch/foo*bar_foobar3060=== CONT TestGlobMatch/*bar_foo3061=== CONT TestGlobMatch/*bar_foobar3062=== CONT TestGlobMatch/*bar_bar3063=== CONT TestGlobMatch/foo*_bar3064=== CONT TestGlobMatch/foo*_foobar3065=== CONT TestGlobMatch/foo*_foo3066=== CONT TestGlobMatch/*_anything3067=== CONT TestGlobMatch/*_3068=== CONT TestGlobMatch/foo_bar3069--- PASS: TestGlobMatch (0.00s)3070 --- PASS: TestGlobMatch/foo_foo (0.00s)3071 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3072 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3073 --- PASS: TestGlobMatch/?oo_boo (0.00s)3074 --- PASS: TestGlobMatch/?oo_foo (0.00s)3075 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3076 --- PASS: TestGlobMatch/fo?_fo (0.00s)3077 --- PASS: TestGlobMatch/fo?_foo (0.00s)3078 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3079 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3080 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3081 --- PASS: TestGlobMatch/*/*_foo (0.00s)3082 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3083 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3084 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3085 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3086 --- PASS: TestGlobMatch/*bar_foo (0.00s)3087 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3088 --- PASS: TestGlobMatch/*bar_bar (0.00s)3089 --- PASS: TestGlobMatch/foo*_bar (0.00s)3090 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3091 --- PASS: TestGlobMatch/foo*_foo (0.00s)3092 --- PASS: TestGlobMatch/*_anything (0.00s)3093 --- PASS: TestGlobMatch/*_ (0.00s)3094 --- PASS: TestGlobMatch/foo_bar (0.00s)3095--- PASS: TestScopes_ConfigValidation (0.00s)3096--- PASS: TestPins_ConfigValidation (0.00s)30972026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42253/oidc3098--- PASS: TestValidateToken_Expired (0.05s)30992026/10/01 08:31:00 http: TLS handshake error from 127.0.0.1:48112: remote error: tls: bad certificate3100--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)31012026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34517/oidc3102--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)31032026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33339/oidc3104--- PASS: TestValidateToken_WrongAudience (0.08s)31052026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35073/oidc3106--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)31072026/10/01 08:31:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12331082026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40761/oidc3109--- PASS: TestPins_TopLevelShorthand (0.10s)3110--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)31112026/10/01 08:31:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36821/oidc3112--- PASS: TestValidateToken_NoMatchingProvider (0.12s)31132026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42315/oidc3114--- PASS: TestScopes_Rules (0.13s)31152026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44045/oidc3116--- PASS: TestPins_ReservedForMatchingRule (0.17s)31172026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39077/oidc3118--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.18s)31192026/10/01 08:31:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:449753120--- PASS: TestValidateToken_KubernetesServiceAccount (0.21s)31212026/10/01 08:31:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35267/oidc3122--- PASS: TestValidateToken_ValidToken (0.26s)31232026/10/01 08:31:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37241/oidc31242026/10/01 08:31:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34133/oidc3125--- PASS: TestValidateToken_MultipleProviders (0.26s)3126PASS3127Running hook tests...3128=== RUN TestSendPathsEmpty3129=== PAUSE TestSendPathsEmpty3130=== RUN TestQueueEnqueueAndFetch3131=== PAUSE TestQueueEnqueueAndFetch3132=== RUN TestQueueDeduplication3133=== PAUSE TestQueueDeduplication3134=== RUN TestQueueRemove3135=== PAUSE TestQueueRemove3136=== RUN TestQueueFetchBatchLimit3137=== PAUSE TestQueueFetchBatchLimit3138=== RUN TestQueueRetryMovesToBack3139=== PAUSE TestQueueRetryMovesToBack3140=== RUN TestQueueFetchRemoveLifecycle3141=== PAUSE TestQueueFetchRemoveLifecycle3142=== RUN TestQueueConcurrentWriters3143=== PAUSE TestQueueConcurrentWriters3144=== RUN TestQueueRemoveLargeClosure3145=== PAUSE TestQueueRemoveLargeClosure3146=== RUN TestServerClientIntegration3147=== PAUSE TestServerClientIntegration3148=== RUN TestServerQueueError3149=== PAUSE TestServerQueueError3150=== RUN TestGetListenerSocketActivation3151 server_test.go:210: === RUN TestGetListenerSocketActivation3152 --- PASS: TestGetListenerSocketActivation (0.00s)3153 PASS3154 3155--- PASS: TestGetListenerSocketActivation (0.01s)3156=== RUN TestDrainIsolatesPoisonPath3157=== PAUSE TestDrainIsolatesPoisonPath3158=== RUN TestRunNotBlockedByPoisonHead3159=== PAUSE TestRunNotBlockedByPoisonHead3160=== RUN TestDrainGivesUpWhenServerDown3161=== PAUSE TestDrainGivesUpWhenServerDown3162=== RUN TestFailedPathPrunedByLaterClosure3163=== PAUSE TestFailedPathPrunedByLaterClosure3164=== RUN TestWorkerUploadsAndRemoves3165=== PAUSE TestWorkerUploadsAndRemoves3166=== RUN TestWorkerSkipsGCdPaths3167=== PAUSE TestWorkerSkipsGCdPaths3168=== RUN TestWorkerPrunesClosureDeps3169=== PAUSE TestWorkerPrunesClosureDeps3170=== RUN TestDrainTimeout3171=== PAUSE TestDrainTimeout3172=== CONT TestSendPathsEmpty3173=== CONT TestDrainIsolatesPoisonPath3174=== CONT TestWorkerSkipsGCdPaths3175--- PASS: TestSendPathsEmpty (0.00s)3176=== CONT TestQueueRetryMovesToBack3177=== CONT TestQueueFetchBatchLimit3178=== CONT TestQueueRemove3179=== CONT TestQueueDeduplication3180=== CONT TestQueueEnqueueAndFetch3181=== CONT TestWorkerUploadsAndRemoves3182=== CONT TestDrainTimeout3183=== CONT TestWorkerPrunesClosureDeps3184=== CONT TestDrainGivesUpWhenServerDown3185=== CONT TestFailedPathPrunedByLaterClosure3186=== CONT TestRunNotBlockedByPoisonHead3187=== CONT TestServerClientIntegration3188=== CONT TestServerQueueError3189=== CONT TestQueueRemoveLargeClosure3190=== CONT TestQueueConcurrentWriters3191=== CONT TestQueueFetchRemoveLifecycle31922026/10/01 08:31:00 ERROR Failed to queue paths error="permission denied" count=13193--- PASS: TestServerClientIntegration (0.00s)3194--- PASS: TestServerQueueError (0.00s)31952026/10/01 08:31:00 INFO Uploading batch count=131962026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=131972026/10/01 08:31:00 INFO Uploading batch count=231982026/10/01 08:31:00 INFO Uploading batch count=431992026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=432002026/10/01 08:31:00 INFO Upload queue status pending=232012026/10/01 08:31:00 INFO Uploading batch count=132022026/10/01 08:31:00 INFO Upload queue status pending=232032026/10/01 08:31:00 INFO Uploading batch count=132042026/10/01 08:31:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2496381185/002/nonexistent32052026/10/01 08:31:00 INFO Uploading batch count=132062026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1253678168/002/bbb3207--- PASS: TestQueueEnqueueAndFetch (0.02s)32082026/10/01 08:31:00 INFO Uploading batch count=232092026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=232102026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2227240397/002/a3211--- PASS: TestQueueRetryMovesToBack (0.02s)32122026/10/01 08:31:00 INFO Upload queue status pending=232132026/10/01 08:31:00 INFO Upload queue status pending=332142026/10/01 08:31:00 INFO Uploading batch count=132152026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2227240397/002/b32162026/10/01 08:31:00 INFO Uploading batch count=23217--- PASS: TestQueueFetchBatchLimit (0.02s)3218--- PASS: TestQueueFetchRemoveLifecycle (0.02s)32192026/10/01 08:31:00 INFO Uploading batch count=132202026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=13221--- PASS: TestQueueRemove (0.02s)3222--- PASS: TestQueueDeduplication (0.02s)32232026/10/01 08:31:00 INFO Uploading batch count=232242026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=232252026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2227240397/002/c32262026/10/01 08:31:00 INFO Uploading batch count=132272026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=132282026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2227240397/002/d32292026/10/01 08:31:00 INFO Uploading batch count=132302026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=132312026/10/01 08:31:00 INFO Uploading batch count=232322026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=232332026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2227240397/002/e32342026/10/01 08:31:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2227240397/002/f32352026/10/01 08:31:00 INFO Uploading batch count=13236--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)32372026/10/01 08:31:00 ERROR Upload failed error="upload failed" count=132382026/10/01 08:31:00 ERROR Drain finished with paths left in queue remaining=1032392026/10/01 08:31:00 ERROR Drain finished with paths left in queue remaining=13240--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3241--- PASS: TestDrainIsolatesPoisonPath (0.02s)3242--- PASS: TestWorkerUploadsAndRemoves (0.04s)3243--- PASS: TestWorkerPrunesClosureDeps (0.04s)3244--- PASS: TestWorkerSkipsGCdPaths (0.04s)3245--- PASS: TestQueueRemoveLargeClosure (0.14s)3246--- PASS: TestQueueConcurrentWriters (0.16s)32472026/10/01 08:31:01 ERROR Upload failed error="context deadline exceeded" count=232482026/10/01 08:31:01 ERROR Drain finished with paths left in queue remaining=43249--- PASS: TestDrainTimeout (0.22s)32502026/10/01 08:31:01 INFO Uploading batch count=132512026/10/01 08:31:01 INFO Uploading batch count=132522026/10/01 08:31:01 INFO Uploading batch count=132532026/10/01 08:31:01 ERROR Upload failed error="upload failed" count=132542026/10/01 08:31:01 INFO Uploading batch count=132552026/10/01 08:31:01 ERROR Upload failed error="upload failed" count=132562026/10/01 08:31:01 INFO Uploading batch count=132572026/10/01 08:31:01 ERROR Upload failed error="upload failed" count=132582026/10/01 08:31:01 INFO Uploading batch count=132592026/10/01 08:31:01 ERROR Upload failed error="upload failed" count=132602026/10/01 08:31:01 ERROR Drain finished with paths left in queue remaining=13261--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3262PASS