niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #293
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.10s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestSetClientTLSErrors97=== CONT TestScriptTokenEmptyCommand98=== CONT TestFileTokenReadsAndCaches99=== CONT TestScriptTokenScriptFails100=== CONT TestScriptTokenBadJSON101=== CONT TestScriptTokenEmptyToken102=== CONT TestScriptTokenCachesUntilRefresh103=== CONT TestScriptTokenNoExpiryRerunsEveryCall104=== CONT TestFileTokenEmpty105--- PASS: TestShellSplit (0.00s)106--- PASS: TestScriptTokenEmptyCommand (0.00s)107=== CONT TestFileTokenMissing108--- PASS: TestDoServerRequestAttachesToken (0.00s)109=== CONT TestEncodeNixBase32WithRealHash110--- PASS: TestEncodeNixBase32WithRealHash (0.00s)111=== CONT TestStaticToken112--- PASS: TestStaticToken (0.00s)113=== CONT TestDoWithRetry_BodyReplayedViaGetBody1142026/10/01 07:38:30 WARN Rate limiter enabled after throttle name=server-test rate=51152026/10/01 07:38:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:571401162026/10/01 07:38:30 WARN Rate limiter backed off name=server-test rate=51172026/10/01 07:38:30 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57140118--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)119=== CONT TestResolveStorePath120--- PASS: TestFileTokenReadsAndCaches (0.00s)121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1222026/10/01 07:38:30 WARN Rate limiter enabled after throttle name=server-test rate=5123--- PASS: TestScriptTokenScriptFails (0.01s)124=== CONT TestStreamPushRequestLine1252026/10/01 07:38:30 ERROR Upload failed error=boom count=1126--- PASS: TestFileTokenMissing (0.01s)127=== CONT TestRateLimiterFeedback128=== RUN TestRateLimiterFeedback/429_enables_limiter129=== PAUSE TestRateLimiterFeedback/429_enables_limiter130=== RUN TestRateLimiterFeedback/503_enables_limiter131=== PAUSE TestRateLimiterFeedback/503_enables_limiter132=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter133=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter134=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter135=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter136=== CONT TestSetClientTLSDoesNotMutateDefaultTransport137=== RUN TestSetClientTLSErrors/missing_cert_file138=== PAUSE TestSetClientTLSErrors/missing_cert_file139=== RUN TestSetClientTLSErrors/missing_key_file140=== PAUSE TestSetClientTLSErrors/missing_key_file141=== RUN TestSetClientTLSErrors/missing_ca_file142=== PAUSE TestSetClientTLSErrors/missing_ca_file143=== RUN TestSetClientTLSErrors/invalid_ca_file144=== PAUSE TestSetClientTLSErrors/invalid_ca_file145=== CONT TestPathInfoCACompatibility146=== RUN TestPathInfoCACompatibility/null_ca_field147=== PAUSE TestPathInfoCACompatibility/null_ca_field148=== RUN TestPathInfoCACompatibility/old_string_format_-_text149=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text150=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive152=== RUN TestPathInfoCACompatibility/new_structured_format_-_text153=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text154=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method155=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method156=== CONT TestSetClientTLS157--- PASS: TestFileTokenEmpty (0.01s)158=== CONT TestParsePathInfoJSONMultiplePaths159=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths162=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== CONT TestClientSignaturesByStorePath164--- PASS: TestClientSignaturesByStorePath (0.00s)165=== CONT TestParsePathInfoJSON166=== RUN TestParsePathInfoJSON/Nix_format167=== PAUSE TestParsePathInfoJSON/Nix_format168=== RUN TestParsePathInfoJSON/Lix_format169=== PAUSE TestParsePathInfoJSON/Lix_format170=== RUN TestParsePathInfoJSON/empty_input171=== PAUSE TestParsePathInfoJSON/empty_input172=== RUN TestParsePathInfoJSON/whitespace_only173=== PAUSE TestParsePathInfoJSON/whitespace_only174=== RUN TestParsePathInfoJSON/invalid_JSON175=== PAUSE TestParsePathInfoJSON/invalid_JSON176=== CONT TestStreamPushReportsSignatures1772026/10/01 07:38:30 ERROR Upload failed error=boom count=1178--- PASS: TestStreamPushReportsSignatures (0.00s)179=== CONT TestPathInfoHashCompatibility180=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)182=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon183=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon184=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512187=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512188=== CONT TestGetStorePathHash189=== RUN TestGetStorePathHash/valid_store_path190=== PAUSE TestGetStorePathHash/valid_store_path191=== RUN TestGetStorePathHash/basename_without_hyphen_should_error192=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error193=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error194=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error195=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error196=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error197=== CONT TestConvertHashToNix32198=== RUN TestConvertHashToNix32/SRI_format_to_Nix32199=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32200=== RUN TestConvertHashToNix32/already_Nix32_format201=== PAUSE TestConvertHashToNix32/already_Nix32_format202=== RUN TestConvertHashToNix32/invalid_format203=== PAUSE TestConvertHashToNix32/invalid_format204=== CONT TestUploadMultipart_SupersededByPeer205=== RUN TestUploadMultipart_SupersededByPeer/exists206=== PAUSE TestUploadMultipart_SupersededByPeer/exists207=== RUN TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestUploadMultipart_SupersededByPeer/missing209=== CONT TestEncodeNixBase32210=== RUN TestEncodeNixBase32/test_string_hash211=== PAUSE TestEncodeNixBase32/test_string_hash212=== RUN TestEncodeNixBase32/empty_input213=== PAUSE TestEncodeNixBase32/empty_input214=== CONT TestDumpPathWriterError215--- PASS: TestResolveStorePath (0.01s)216=== CONT TestStreamPushBatchesUnderLoad217--- PASS: TestStreamPushRequestLine (0.01s)218=== CONT TestDumpPathSingleFile219--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)220=== CONT TestStreamPushGivesUpOnDeadServer2212026/10/01 07:38:30 ERROR Upload failed error="connection refused" count=202222026/10/01 07:38:30 ERROR Server seems unavailable, giving up on batch untried=17223--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)224=== CONT TestDumpPathMatchesNix225--- PASS: TestScriptTokenEmptyToken (0.02s)226=== CONT TestStreamPushIsolatesFailures2272026/10/01 07:38:30 ERROR Upload failed error="bad path" count=3228--- PASS: TestScriptTokenBadJSON (0.02s)229=== CONT TestPartSizeForNAR230=== RUN TestPartSizeForNAR/zero_stays_at_minimum231--- PASS: TestStreamPushIsolatesFailures (0.00s)232=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum233=== RUN TestPartSizeForNAR/small_stays_at_minimum234=== PAUSE TestPartSizeForNAR/small_stays_at_minimum235=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum237=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts238=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts239=== CONT TestUploadMultipart_PartsInParallel240=== RUN TestPartSizeForNAR/1_TiB241=== PAUSE TestPartSizeForNAR/1_TiB242=== RUN TestPartSizeForNAR/5_TiB_S3_max_object243=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object244=== RUN TestPartSizeForNAR/capped_at_5_GiB245=== PAUSE TestPartSizeForNAR/capped_at_5_GiB246=== CONT TestCaseHackSuffix247=== RUN TestSetClientTLS/rejects_connection_without_client_cert248=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert249=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA250=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA251=== RUN TestSetClientTLS/preserves_debug_logging_transport252=== PAUSE TestSetClientTLS/preserves_debug_logging_transport253=== CONT TestRegisterUploadedObjectReusesConnections254--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)255=== CONT TestStreamPushReportsEveryPath256--- PASS: TestStreamPushReportsEveryPath (0.00s)257=== CONT TestShellSplitErrors258--- PASS: TestShellSplitErrors (0.00s)259=== CONT TestFilterOversizedClosures260=== RUN TestFilterOversizedClosures/no_limit_keeps_everything261=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything262=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped263=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped264=== RUN TestFilterOversizedClosures/all_closures_skipped265=== PAUSE TestFilterOversizedClosures/all_closures_skipped266=== CONT TestRateLimiterFeedback/429_enables_limiter2672026/10/01 07:38:30 WARN Rate limiter enabled after throttle name=server-test rate=52682026/10/01 07:38:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:572172692026/10/01 07:38:30 WARN Rate limiter backed off name=server-test rate=5270=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter271=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter272=== CONT TestRateLimiterFeedback/503_enables_limiter2732026/10/01 07:38:30 WARN Rate limiter enabled after throttle name=server-test rate=52742026/10/01 07:38:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:572232752026/10/01 07:38:30 WARN Rate limiter backed off name=server-test rate=5276--- PASS: TestRateLimiterFeedback (0.00s)277 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)278 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)279 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)280 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)281=== CONT TestSetClientTLSErrors/missing_cert_file282=== CONT TestSetClientTLSErrors/missing_ca_file283=== CONT TestSetClientTLSErrors/invalid_ca_file284=== CONT TestSetClientTLSErrors/missing_key_file285=== CONT TestPathInfoCACompatibility/null_ca_field286=== CONT TestPathInfoCACompatibility/new_structured_format_-_text287=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method288=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive289=== CONT TestPathInfoCACompatibility/old_string_format_-_text290--- PASS: TestPathInfoCACompatibility (0.00s)291 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)292 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)293 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)295 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)296=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths297=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths298--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)299 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)301=== CONT TestParsePathInfoJSON/Nix_format302=== CONT TestParsePathInfoJSON/invalid_JSON303=== CONT TestParsePathInfoJSON/whitespace_only304=== CONT TestParsePathInfoJSON/empty_input305=== CONT TestParsePathInfoJSON/Lix_format306--- PASS: TestParsePathInfoJSON (0.00s)307 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)308 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)309 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)310 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)311 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)313=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI314=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512315=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon316--- PASS: TestPathInfoHashCompatibility (0.00s)317 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)318 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)320 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)321=== CONT TestGetStorePathHash/valid_store_path322=== CONT TestConvertHashToNix32/SRI_format_to_Nix32323=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error324=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error325=== CONT TestGetStorePathHash/basename_without_hyphen_should_error326--- PASS: TestGetStorePathHash (0.00s)327 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)328 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)330 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)331=== CONT TestUploadMultipart_SupersededByPeer/exists332=== CONT TestConvertHashToNix32/invalid_format333=== CONT TestConvertHashToNix32/already_Nix32_format334--- PASS: TestConvertHashToNix32 (0.00s)335 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)336 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)337 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)338=== CONT TestUploadMultipart_SupersededByPeer/missing339--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)340 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)341 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)342=== CONT TestEncodeNixBase32/test_string_hash343=== CONT TestEncodeNixBase32/empty_input344--- PASS: TestEncodeNixBase32 (0.00s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346 --- PASS: TestEncodeNixBase32/empty_input (0.00s)347=== CONT TestPartSizeForNAR/zero_stays_at_minimum348=== CONT TestPartSizeForNAR/1_TiB349=== CONT TestPartSizeForNAR/capped_at_5_GiB350=== CONT TestPartSizeForNAR/5_TiB_S3_max_object351=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum352=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts353=== CONT TestPartSizeForNAR/small_stays_at_minimum354--- PASS: TestPartSizeForNAR (0.00s)355 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)357 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)358 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)359 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)361 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)362=== CONT TestSetClientTLS/rejects_connection_without_client_cert363--- PASS: TestSetClientTLSErrors (0.01s)364 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)365 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)366 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)367 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)368--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)369=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA370=== CONT TestSetClientTLS/preserves_debug_logging_transport3712026/10/01 07:38:30 http: TLS handshake error from 127.0.0.1:57229: remote error: tls: bad certificate372=== CONT TestFilterOversizedClosures/no_limit_keeps_everything373=== CONT TestFilterOversizedClosures/all_closures_skipped3742026/10/01 07:38:30 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50375=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3762026/10/01 07:38:30 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000377--- PASS: TestFilterOversizedClosures (0.00s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)381--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)382--- PASS: TestSetClientTLS (0.01s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386--- PASS: TestDumpPathWriterError (0.07s)387--- PASS: TestCaseHackSuffix (0.08s)388--- PASS: TestDumpPathSingleFile (0.10s)389--- PASS: TestStreamPushBatchesUnderLoad (0.10s)390--- PASS: TestDumpPathMatchesNix (0.15s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld14".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-67309-3657216313/postgres2349481097/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-67309-3657216313/postgres2349481097/data -l logfile start421422/nix/var/nix/builds/nix-67309-3657216313/postgres2349481097:5432 - no response4232026-10-01 07:38:35.702 UTC [67974] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 07:38:35.728 UTC [67974] LOG: listening on Unix socket "/nix/var/nix/builds/nix-67309-3657216313/postgres2349481097/.s.PGSQL.5432"4252026-10-01 07:38:35.736 UTC [67986] LOG: database system was shut down at 2026-10-01 07:38:35 UTC4262026-10-01 07:38:35.743 UTC [67974] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-67309-3657216313/postgres2349481097:5432 - accepting connections428{"timestamp":"2026-10-01T07:38:35.993274Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3234705b-ee21-48df-87bc-d7d36c4ff0d6","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(6)"}429{"timestamp":"2026-10-01T07:38:36.094188Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"fcdebe13-5a72-4d04-99b2-a576e86b81c4","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(4)"}430{"timestamp":"2026-10-01T07:38:36.196033Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a477a7d6-d27c-454a-bf16-bfa1a8521916","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(11)"}431{"timestamp":"2026-10-01T07:38:36.299064Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4951623f-57f0-4335-a5a6-fbc7f5197828","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(3)"}432{"timestamp":"2026-10-01T07:38:36.401795Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f0e7c500-46e3-40b3-8817-15a104e5ec63","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(6)"}433=== RUN TestService_AuthMiddleware434=== PAUSE TestService_AuthMiddleware435=== RUN TestService_AuthMiddleware_MTLSProxyHeader436=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader437=== RUN TestService_AuthMiddleware_MTLSBoundSubjects438=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects439=== RUN TestService_ReadAuthMiddleware440=== PAUSE TestService_ReadAuthMiddleware441=== RUN TestService_AuthMiddleware_OIDC442=== PAUSE TestService_AuthMiddleware_OIDC443=== RUN TestService_RequireScope_OIDC444=== PAUSE TestService_RequireScope_OIDC445=== RUN TestService_ReadScope_PublicByDefault446=== PAUSE TestService_ReadScope_PublicByDefault447=== RUN TestCacheConfigHandler448=== PAUSE TestCacheConfigHandler449=== RUN TestCacheStatsHandler450=== PAUSE TestCacheStatsHandler451=== RUN TestClientCADerivations452=== PAUSE TestClientCADerivations453=== RUN TestClientErrorHandling454=== PAUSE TestClientErrorHandling455=== RUN TestClientIntegration456=== PAUSE TestClientIntegration457=== RUN TestClientMultipleUploads458=== PAUSE TestClientMultipleUploads459=== RUN TestClientWithDependencies460=== PAUSE TestClientWithDependencies461=== RUN TestClientSharedPathCommittedMidPush462=== PAUSE TestClientSharedPathCommittedMidPush463=== RUN TestPinProtectsFromGC464=== PAUSE TestPinProtectsFromGC465=== RUN TestClientPushesUseOnePush466=== PAUSE TestClientPushesUseOnePush467=== RUN TestClientFallsBackToClosures468=== PAUSE TestClientFallsBackToClosures469=== RUN TestResolveDBConnectionString470=== PAUSE TestResolveDBConnectionString471=== RUN TestLeadElectsOneAndHandsOver472=== PAUSE TestLeadElectsOneAndHandsOver473=== RUN TestLeadIncumbentWinsAfterRestart4742026-10-01 07:38:38.511 UTC [68248] ERROR: relation "goose_db_version" does not exist at character 364752026-10-01 07:38:38.511 UTC [68248] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4762026/10/01 07:38:38 OK 20241026095416_initial_model.sql (122.98ms)4772026/10/01 07:38:38 OK 20251210153512_drop_unused_gin_index.sql (18.81ms)4782026/10/01 07:38:38 OK 20251218171726_add_pins.sql (37.3ms)4792026/10/01 07:38:38 OK 20260628120000_add_object_size_and_stats.sql (53.01ms)4802026/10/01 07:38:38 OK 20260905000000_add_claims.sql (51.59ms)4812026/10/01 07:38:38 OK 20260920000000_drop_claims.sql (39.11ms)4822026/10/01 07:38:38 OK 20260923120000_add_pushes.sql (38.1ms)4832026/10/01 07:38:38 goose: successfully migrated database to version: 202609231200004842026/10/01 07:38:38 OK 1_commit_pending_closure.sql (9.33ms)4852026/10/01 07:38:38 OK 2_object_stats_trigger.sql (4.19ms)4862026/10/01 07:38:38 OK 3_commit_push.sql (2.82ms)4872026/10/01 07:38:38 goose: up to current file version: 34882026/10/01 07:38:39 INFO lead: acquired remote=192.0.2.1:12344892026/10/01 07:38:39 INFO lead: released remote=192.0.2.1:12344902026/10/01 07:38:39 INFO lead: acquired remote=192.0.2.1:12344912026/10/01 07:38:39 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (3.40s)493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestGCAdvisoryLockBlocksConcurrentRun4962026-10-01 07:38:41.086 UTC [68453] ERROR: relation "goose_db_version" does not exist at character 364972026-10-01 07:38:41.086 UTC [68453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4982026/10/01 07:38:41 OK 20241026095416_initial_model.sql (61.99ms)4992026/10/01 07:38:41 OK 20251210153512_drop_unused_gin_index.sql (18.64ms)5002026/10/01 07:38:41 OK 20251218171726_add_pins.sql (24.97ms)5012026/10/01 07:38:41 OK 20260628120000_add_object_size_and_stats.sql (35.41ms)5022026/10/01 07:38:41 OK 20260905000000_add_claims.sql (46.86ms)5032026/10/01 07:38:41 OK 20260920000000_drop_claims.sql (6.86ms)5042026/10/01 07:38:41 OK 20260923120000_add_pushes.sql (13.03ms)5052026/10/01 07:38:41 goose: successfully migrated database to version: 202609231200005062026/10/01 07:38:41 OK 1_commit_pending_closure.sql (2.06ms)5072026/10/01 07:38:41 OK 2_object_stats_trigger.sql (598.75µs)5082026/10/01 07:38:41 OK 3_commit_push.sql (456.88µs)5092026/10/01 07:38:41 goose: up to current file version: 3510--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.75s)511=== RUN TestGCBugBareHashReferences512=== PAUSE TestGCBugBareHashReferences513=== RUN TestGCMetrics514=== PAUSE TestGCMetrics515=== RUN TestPushDedupSurvivesConcurrentGC516=== PAUSE TestPushDedupSurvivesConcurrentGC517=== RUN TestDeduplicatedObjectsRecordedAsPending518=== PAUSE TestDeduplicatedObjectsRecordedAsPending519=== RUN TestGCSweepSkipsPendingObjects520=== PAUSE TestGCSweepSkipsPendingObjects521=== RUN TestTombstonedObjectOfferedWithoutWaiting522=== PAUSE TestTombstonedObjectOfferedWithoutWaiting523=== RUN TestGCSweepDeliversEachKeyOnce524=== PAUSE TestGCSweepDeliversEachKeyOnce525=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection527=== RUN TestGCTaskStore_StartNew528=== PAUSE TestGCTaskStore_StartNew529=== RUN TestGCTaskStore_DeduplicateSameParams530=== PAUSE TestGCTaskStore_DeduplicateSameParams531=== RUN TestGCTaskStore_ConflictDifferentParams532=== PAUSE TestGCTaskStore_ConflictDifferentParams533=== RUN TestGCTaskStore_GetEmpty534=== PAUSE TestGCTaskStore_GetEmpty535=== RUN TestGCTaskStore_GetReturnsLatest536=== PAUSE TestGCTaskStore_GetReturnsLatest537=== RUN TestGCTaskStore_CompletedAllowsNewTask538=== PAUSE TestGCTaskStore_CompletedAllowsNewTask539=== RUN TestGCTaskStore_PhaseUpdates540=== PAUSE TestGCTaskStore_PhaseUpdates541=== RUN TestGCTaskStore_Fail542=== PAUSE TestGCTaskStore_Fail543=== RUN TestGracefulShutdownDrainsInflight544=== PAUSE TestGracefulShutdownDrainsInflight545=== RUN TestService_healthCheckHandler546=== PAUSE TestService_healthCheckHandler547=== RUN TestService_readinessHandler548=== PAUSE TestService_readinessHandler549=== RUN TestGenerateLandingPage550=== PAUSE TestGenerateLandingPage551=== RUN TestCacheConfigHandlerMaxNarSize552=== PAUSE TestCacheConfigHandlerMaxNarSize553=== RUN TestCreatePendingClosureRejectsOversizedNAR554=== PAUSE TestCreatePendingClosureRejectsOversizedNAR555=== RUN TestNARDeduplicationMetadataUploadBug556=== PAUSE TestNARDeduplicationMetadataUploadBug557=== RUN TestMetricsInventory558=== PAUSE TestMetricsInventory559=== RUN TestService_NativeMTLS560=== PAUSE TestService_NativeMTLS561=== RUN TestServerTLSConfig562=== PAUSE TestServerTLSConfig563=== RUN TestMultipartCleanup564=== PAUSE TestMultipartCleanup565=== RUN TestObjectStatsTrigger566=== PAUSE TestObjectStatsTrigger567=== RUN TestOrphanedObjectsGC568=== PAUSE TestOrphanedObjectsGC569=== RUN TestOrphanedObjectsGCStressTest570=== PAUSE TestOrphanedObjectsGCStressTest571=== RUN TestResurrectedObjectNotDeleted572=== PAUSE TestResurrectedObjectNotDeleted573=== RUN TestCreatePin_ReservedPins574=== PAUSE TestCreatePin_ReservedPins575=== RUN TestParseSingleRange576=== PAUSE TestParseSingleRange577=== RUN TestProxyHeadersOnlyTrustedOnSocket578=== PAUSE TestProxyHeadersOnlyTrustedOnSocket579=== RUN TestIsValidCachePath580=== PAUSE TestIsValidCachePath581=== RUN TestReadProxyNarinfo582=== PAUSE TestReadProxyNarinfo583=== RUN TestReadProxyNarinfoAlreadyDecompressed584=== PAUSE TestReadProxyNarinfoAlreadyDecompressed585=== RUN TestReadProxyNarStreaming586=== PAUSE TestReadProxyNarStreaming587=== RUN TestReadProxy404588=== PAUSE TestReadProxy404589=== RUN TestReadProxyInvalidPath590=== PAUSE TestReadProxyInvalidPath591=== RUN TestReadProxyHead592=== PAUSE TestReadProxyHead593=== RUN TestReadProxyConditionalGet594=== PAUSE TestReadProxyConditionalGet595=== RUN TestReadProxyRootRedirectsToIndexHTML596=== PAUSE TestReadProxyRootRedirectsToIndexHTML597=== RUN TestReadProxyDisabled598=== PAUSE TestReadProxyDisabled599=== RUN TestReadRedirectNar600=== PAUSE TestReadRedirectNar601=== RUN TestReadRedirectKeepsNarinfoProxied602=== PAUSE TestReadRedirectKeepsNarinfoProxied603=== RUN TestReadProxyRangeRequest604=== PAUSE TestReadProxyRangeRequest605=== RUN TestReadRedirectUsesPublicS3URL606=== PAUSE TestReadRedirectUsesPublicS3URL607=== RUN TestPush_OverlappingRootsStoreOneRowPerKey608=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey609=== RUN TestPush_CompleteCommitsEveryRoot610=== PAUSE TestPush_CompleteCommitsEveryRoot611=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit612=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit613=== RUN TestPush_RejectsBadRequests614=== PAUSE TestPush_RejectsBadRequests615=== RUN TestPush_SignsNarinfosOfItsPendingObjects616=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects617=== RUN TestRedundantMultipartUpload618=== PAUSE TestRedundantMultipartUpload619=== RUN TestCompleteMultipartUpload_ErrorButObjectExists620=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists621=== RUN TestCompletedNarNotReofferedAcrossClosures622=== PAUSE TestCompletedNarNotReofferedAcrossClosures623=== RUN TestPresignedUploadRegisteredBeforeCommit624=== PAUSE TestPresignedUploadRegisteredBeforeCommit625=== RUN TestService_Rustfstest626=== PAUSE TestService_Rustfstest627=== RUN TestParseSize628=== PAUSE TestParseSize629=== RUN TestSkippedUploadsHandler630=== PAUSE TestSkippedUploadsHandler631=== RUN TestSystemdListenerNotActivated632--- PASS: TestSystemdListenerNotActivated (0.00s)633=== RUN TestWatchdogBeatsWhenHealthy634--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)635=== RUN TestWatchdogSkipsWhenUnhealthy6362026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 07:38:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"646--- PASS: TestWatchdogSkipsWhenUnhealthy (0.22s)647=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle648=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle649=== RUN TestProxyWriteTimeout650=== PAUSE TestProxyWriteTimeout651=== RUN TestIsValidUploadKey652=== PAUSE TestIsValidUploadKey653=== RUN TestUploadHandlersRejectInvalidKeys654=== PAUSE TestUploadHandlersRejectInvalidKeys655=== RUN TestUploadHandlersRejectOversizedBody656=== PAUSE TestUploadHandlersRejectOversizedBody657=== RUN TestService_cleanupPendingClosuresHandler658=== PAUSE TestService_cleanupPendingClosuresHandler659=== RUN TestService_createPendingClosureHandler660=== PAUSE TestService_createPendingClosureHandler661=== RUN TestService_verifyS3Integrity662=== PAUSE TestService_verifyS3Integrity663=== RUN TestCompleteMultipartUnregistered664=== PAUSE TestCompleteMultipartUnregistered665=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT666=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT667=== CONT TestReadRedirectUsesPublicS3URL668=== CONT TestService_AuthMiddleware669=== CONT TestGCTaskStore_CompletedAllowsNewTask670--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)671=== CONT TestReadProxyRangeRequest672=== CONT TestResurrectedObjectNotDeleted673=== CONT TestOrphanedObjectsGCStressTest674=== CONT TestCreatePendingClosureRejectsOversizedNAR675=== CONT TestService_healthCheckHandler676=== CONT TestGracefulShutdownDrainsInflight677=== CONT TestGCTaskStore_Fail678=== CONT TestGCTaskStore_PhaseUpdates679--- PASS: TestGCTaskStore_Fail (0.00s)680=== CONT TestReadRedirectKeepsNarinfoProxied681--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)682=== CONT TestReadRedirectNar6832026/10/01 07:38:41 INFO Received uploads request method=POST path=/api/pending_closures684--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)685=== CONT TestReadProxyDisabled6862026/10/01 07:38:41 INFO Starting HTTP server address=127.0.0.1:573836872026/10/01 07:38:41 INFO Shutdown signal received, draining in-flight requests timeout=10s688--- PASS: TestGracefulShutdownDrainsInflight (0.09s)689=== CONT TestReadProxyRootRedirectsToIndexHTML6902026-10-01 07:38:43.386 UTC [68586] ERROR: relation "goose_db_version" does not exist at character 366912026-10-01 07:38:43.386 UTC [68586] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6922026/10/01 07:38:43 OK 20241026095416_initial_model.sql (139.34ms)6932026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (14.87ms)6942026-10-01 07:38:43.634 UTC [68593] ERROR: relation "goose_db_version" does not exist at character 366952026-10-01 07:38:43.634 UTC [68593] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6962026/10/01 07:38:43 OK 20251218171726_add_pins.sql (47.09ms)6972026-10-01 07:38:43.663 UTC [68592] ERROR: relation "goose_db_version" does not exist at character 366982026-10-01 07:38:43.663 UTC [68592] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6992026-10-01 07:38:43.670 UTC [68595] ERROR: relation "goose_db_version" does not exist at character 367002026-10-01 07:38:43.670 UTC [68595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7012026/10/01 07:38:43 OK 20260628120000_add_object_size_and_stats.sql (38.21ms)7022026/10/01 07:38:43 OK 20260905000000_add_claims.sql (74.85ms)7032026/10/01 07:38:43 OK 20260920000000_drop_claims.sql (11.63ms)7042026-10-01 07:38:43.774 UTC [68598] ERROR: relation "goose_db_version" does not exist at character 367052026-10-01 07:38:43.774 UTC [68598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7062026-10-01 07:38:43.774 UTC [68597] ERROR: relation "goose_db_version" does not exist at character 367072026-10-01 07:38:43.774 UTC [68597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7082026/10/01 07:38:43 OK 20260923120000_add_pushes.sql (3.98ms)7092026/10/01 07:38:43 goose: successfully migrated database to version: 202609231200007102026/10/01 07:38:43 OK 1_commit_pending_closure.sql (2.13ms)7112026/10/01 07:38:43 OK 2_object_stats_trigger.sql (989.67µs)7122026/10/01 07:38:43 OK 3_commit_push.sql (227.42µs)7132026/10/01 07:38:43 goose: up to current file version: 37142026-10-01 07:38:43.810 UTC [68601] ERROR: relation "goose_db_version" does not exist at character 367152026-10-01 07:38:43.810 UTC [68601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026-10-01 07:38:43.810 UTC [68602] ERROR: relation "goose_db_version" does not exist at character 367172026-10-01 07:38:43.810 UTC [68602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7182026/10/01 07:38:43 OK 20241026095416_initial_model.sql (114ms)7192026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (21.69ms)7202026-10-01 07:38:43.841 UTC [68600] ERROR: relation "goose_db_version" does not exist at character 367212026-10-01 07:38:43.841 UTC [68600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026/10/01 07:38:43 OK 20251218171726_add_pins.sql (10.94ms)7232026-10-01 07:38:43.844 UTC [68605] ERROR: relation "goose_db_version" does not exist at character 367242026-10-01 07:38:43.844 UTC [68605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026/10/01 07:38:43 OK 20241026095416_initial_model.sql (97ms)7262026/10/01 07:38:43 OK 20241026095416_initial_model.sql (81.55ms)7272026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)7282026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)7292026/10/01 07:38:43 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)7302026/10/01 07:38:43 OK 20241026095416_initial_model.sql (22.39ms)7312026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (10.4ms)7322026/10/01 07:38:43 OK 20251218171726_add_pins.sql (36ms)7332026/10/01 07:38:43 OK 20251218171726_add_pins.sql (35.97ms)7342026/10/01 07:38:43 OK 20251218171726_add_pins.sql (29.43ms)7352026/10/01 07:38:43 OK 20260905000000_add_claims.sql (54.08ms)7362026/10/01 07:38:43 OK 20260628120000_add_object_size_and_stats.sql (15.68ms)7372026/10/01 07:38:43 OK 20260628120000_add_object_size_and_stats.sql (22.14ms)7382026/10/01 07:38:43 OK 20260628120000_add_object_size_and_stats.sql (21.67ms)7392026/10/01 07:38:43 OK 20241026095416_initial_model.sql (80.09ms)7402026/10/01 07:38:43 OK 20260920000000_drop_claims.sql (11.5ms)7412026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (26.8ms)7422026/10/01 07:38:43 OK 20260923120000_add_pushes.sql (27.03ms)7432026/10/01 07:38:43 goose: successfully migrated database to version: 202609231200007442026/10/01 07:38:43 OK 20260905000000_add_claims.sql (36.17ms)7452026/10/01 07:38:43 OK 20260905000000_add_claims.sql (35.41ms)7462026/10/01 07:38:43 OK 1_commit_pending_closure.sql (1.52ms)7472026/10/01 07:38:43 OK 2_object_stats_trigger.sql (212.46µs)7482026/10/01 07:38:43 OK 3_commit_push.sql (213.13µs)7492026/10/01 07:38:43 goose: up to current file version: 37502026/10/01 07:38:43 OK 20241026095416_initial_model.sql (102.02ms)7512026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (20.9ms)7522026/10/01 07:38:43 OK 20260920000000_drop_claims.sql (29.81ms)7532026/10/01 07:38:43 OK 20260905000000_add_claims.sql (65.86ms)7542026/10/01 07:38:43 OK 20251218171726_add_pins.sql (38.37ms)7552026/10/01 07:38:43 OK 20241026095416_initial_model.sql (132.62ms)7562026/10/01 07:38:43 OK 20241026095416_initial_model.sql (120.79ms)7572026/10/01 07:38:43 OK 20260920000000_drop_claims.sql (49.42ms)7582026/10/01 07:38:43 OK 20260923120000_add_pushes.sql (20.52ms)7592026/10/01 07:38:43 goose: successfully migrated database to version: 202609231200007602026/10/01 07:38:43 OK 1_commit_pending_closure.sql (1.37ms)7612026/10/01 07:38:43 OK 2_object_stats_trigger.sql (243.21µs)7622026/10/01 07:38:43 OK 3_commit_push.sql (300.75µs)7632026/10/01 07:38:43 goose: up to current file version: 37642026/10/01 07:38:43 OK 20260920000000_drop_claims.sql (27.73ms)7652026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (18.3ms)7662026/10/01 07:38:43 OK 20251210153512_drop_unused_gin_index.sql (18.23ms)7672026/10/01 07:38:43 OK 20260923120000_add_pushes.sql (10.01ms)7682026/10/01 07:38:43 goose: successfully migrated database to version: 202609231200007692026/10/01 07:38:44 OK 1_commit_pending_closure.sql (1.6ms)7702026/10/01 07:38:44 OK 2_object_stats_trigger.sql (559.88µs)7712026/10/01 07:38:44 OK 3_commit_push.sql (254.29µs)7722026/10/01 07:38:44 goose: up to current file version: 37732026/10/01 07:38:44 OK 20260628120000_add_object_size_and_stats.sql (39.08ms)7742026/10/01 07:38:44 OK 20251218171726_add_pins.sql (40.33ms)7752026/10/01 07:38:44 OK 20260923120000_add_pushes.sql (32.3ms)7762026/10/01 07:38:44 goose: successfully migrated database to version: 202609231200007772026/10/01 07:38:44 OK 1_commit_pending_closure.sql (1.78ms)7782026/10/01 07:38:44 OK 2_object_stats_trigger.sql (680.63µs)7792026/10/01 07:38:44 OK 3_commit_push.sql (533.88µs)7802026/10/01 07:38:44 goose: up to current file version: 37812026/10/01 07:38:44 OK 20260905000000_add_claims.sql (48.25ms)7822026/10/01 07:38:44 OK 20251218171726_add_pins.sql (59.8ms)7832026/10/01 07:38:44 OK 20241026095416_initial_model.sql (163.54ms)7842026/10/01 07:38:44 OK 20251218171726_add_pins.sql (60.12ms)7852026/10/01 07:38:44 OK 20260628120000_add_object_size_and_stats.sql (10.04ms)7862026/10/01 07:38:44 OK 20260628120000_add_object_size_and_stats.sql (9.88ms)7872026/10/01 07:38:44 OK 20260628120000_add_object_size_and_stats.sql (58.51ms)7882026/10/01 07:38:44 OK 20251210153512_drop_unused_gin_index.sql (18.01ms)789--- PASS: TestReadRedirectKeepsNarinfoProxied (2.19s)790=== CONT TestReadProxyConditionalGet7912026/10/01 07:38:44 OK 20260920000000_drop_claims.sql (58.15ms)7922026/10/01 07:38:44 OK 20251218171726_add_pins.sql (55.23ms)7932026/10/01 07:38:44 OK 20260923120000_add_pushes.sql (23.73ms)7942026/10/01 07:38:44 goose: successfully migrated database to version: 202609231200007952026/10/01 07:38:44 OK 1_commit_pending_closure.sql (1.09ms)7962026/10/01 07:38:44 OK 2_object_stats_trigger.sql (298.58µs)7972026/10/01 07:38:44 OK 3_commit_push.sql (267.46µs)7982026/10/01 07:38:44 goose: up to current file version: 37992026/10/01 07:38:44 OK 20260905000000_add_claims.sql (88.44ms)8002026/10/01 07:38:44 OK 20260628120000_add_object_size_and_stats.sql (38.09ms)8012026/10/01 07:38:44 OK 20260905000000_add_claims.sql (101.44ms)8022026/10/01 07:38:44 OK 20260905000000_add_claims.sql (102.24ms)8032026/10/01 07:38:44 OK 20260920000000_drop_claims.sql (53.95ms)8042026/10/01 07:38:44 OK 20260920000000_drop_claims.sql (53.55ms)8052026/10/01 07:38:44 OK 20260920000000_drop_claims.sql (53.19ms)8062026/10/01 07:38:44 OK 20260923120000_add_pushes.sql (19.32ms)8072026/10/01 07:38:44 goose: successfully migrated database to version: 202609231200008082026/10/01 07:38:44 OK 1_commit_pending_closure.sql (1.08ms)8092026/10/01 07:38:44 OK 2_object_stats_trigger.sql (251.58µs)8102026/10/01 07:38:44 OK 3_commit_push.sql (205.13µs)8112026/10/01 07:38:44 goose: up to current file version: 38122026/10/01 07:38:44 OK 20260923120000_add_pushes.sql (16.29ms)8132026/10/01 07:38:44 goose: successfully migrated database to version: 202609231200008142026/10/01 07:38:44 OK 20260905000000_add_claims.sql (69.93ms)8152026/10/01 07:38:44 OK 1_commit_pending_closure.sql (1.12ms)8162026/10/01 07:38:44 OK 2_object_stats_trigger.sql (352.17µs)8172026/10/01 07:38:44 OK 3_commit_push.sql (218.58µs)8182026/10/01 07:38:44 goose: up to current file version: 38192026/10/01 07:38:44 OK 20260923120000_add_pushes.sql (25.07ms)8202026/10/01 07:38:44 goose: successfully migrated database to version: 202609231200008212026/10/01 07:38:44 OK 1_commit_pending_closure.sql (900.71µs)8222026/10/01 07:38:44 OK 2_object_stats_trigger.sql (202.63µs)8232026/10/01 07:38:44 OK 3_commit_push.sql (174.75µs)8242026/10/01 07:38:44 goose: up to current file version: 38252026/10/01 07:38:44 OK 20260920000000_drop_claims.sql (59.45ms)8262026/10/01 07:38:44 OK 20260923120000_add_pushes.sql (11.95ms)8272026/10/01 07:38:44 goose: successfully migrated database to version: 202609231200008282026/10/01 07:38:44 OK 1_commit_pending_closure.sql (957.92µs)8292026/10/01 07:38:44 OK 2_object_stats_trigger.sql (251.92µs)8302026/10/01 07:38:44 OK 3_commit_push.sql (184.92µs)8312026/10/01 07:38:44 goose: up to current file version: 3832--- PASS: TestService_healthCheckHandler (2.84s)833=== CONT TestReadProxyHead834--- PASS: TestReadProxyRangeRequest (3.17s)835=== CONT TestReadProxyInvalidPath836--- PASS: TestReadProxyDisabled (3.45s)837=== CONT TestReadProxy404838--- PASS: TestReadRedirectNar (3.89s)839=== CONT TestReadProxyNarStreaming8402026/10/01 07:38:46 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"841--- PASS: TestService_AuthMiddleware (4.26s)842=== CONT TestReadProxyNarinfoAlreadyDecompressed843--- PASS: TestReadProxyRootRedirectsToIndexHTML (4.63s)844=== CONT TestReadProxyNarinfo845--- PASS: TestReadRedirectUsesPublicS3URL (5.16s)846=== CONT TestIsValidCachePath847=== RUN TestIsValidCachePath/narinfo848=== PAUSE TestIsValidCachePath/narinfo849=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars850=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars851=== RUN TestIsValidCachePath/nar_zst852=== PAUSE TestIsValidCachePath/nar_zst853=== RUN TestIsValidCachePath/nar_xz854=== PAUSE TestIsValidCachePath/nar_xz855=== RUN TestIsValidCachePath/nar_bz2856=== PAUSE TestIsValidCachePath/nar_bz2857=== RUN TestIsValidCachePath/nar_uncompressed858=== PAUSE TestIsValidCachePath/nar_uncompressed859=== RUN TestIsValidCachePath/ls860=== PAUSE TestIsValidCachePath/ls861=== RUN TestIsValidCachePath/log862=== PAUSE TestIsValidCachePath/log863=== RUN TestIsValidCachePath/realisation864=== PAUSE TestIsValidCachePath/realisation865=== RUN TestIsValidCachePath/nix-cache-info866=== PAUSE TestIsValidCachePath/nix-cache-info867=== RUN TestIsValidCachePath/index.html868=== PAUSE TestIsValidCachePath/index.html869=== RUN TestIsValidCachePath/traversal_parent870=== PAUSE TestIsValidCachePath/traversal_parent871=== RUN TestIsValidCachePath/traversal_in_middle872=== PAUSE TestIsValidCachePath/traversal_in_middle873=== RUN TestIsValidCachePath/invalid_char_e874=== PAUSE TestIsValidCachePath/invalid_char_e875=== RUN TestIsValidCachePath/invalid_char_u876=== PAUSE TestIsValidCachePath/invalid_char_u877=== RUN TestIsValidCachePath/random_path878=== PAUSE TestIsValidCachePath/random_path879=== RUN TestIsValidCachePath/empty880=== PAUSE TestIsValidCachePath/empty881=== RUN TestIsValidCachePath/leading_slash882=== PAUSE TestIsValidCachePath/leading_slash883=== RUN TestIsValidCachePath/wrong_extension884=== PAUSE TestIsValidCachePath/wrong_extension885=== RUN TestIsValidCachePath/short_hash886=== PAUSE TestIsValidCachePath/short_hash887=== CONT TestCacheConfigHandlerMaxNarSize888--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)889=== CONT TestParseSingleRange890=== RUN TestParseSingleRange/none891=== PAUSE TestParseSingleRange/none892=== RUN TestParseSingleRange/unknown_unit893=== PAUSE TestParseSingleRange/unknown_unit894=== RUN TestParseSingleRange/multi-range_ignored895=== PAUSE TestParseSingleRange/multi-range_ignored896=== RUN TestParseSingleRange/malformed_no_dash897=== PAUSE TestParseSingleRange/malformed_no_dash898=== RUN TestParseSingleRange/malformed_both_empty899=== PAUSE TestParseSingleRange/malformed_both_empty900=== RUN TestParseSingleRange/malformed_end_before_start901=== PAUSE TestParseSingleRange/malformed_end_before_start902=== RUN TestParseSingleRange/closed903=== PAUSE TestParseSingleRange/closed904=== RUN TestParseSingleRange/open-ended905=== PAUSE TestParseSingleRange/open-ended906=== RUN TestParseSingleRange/end_clamped_to_size907=== PAUSE TestParseSingleRange/end_clamped_to_size908=== RUN TestParseSingleRange/suffix909=== PAUSE TestParseSingleRange/suffix910=== RUN TestParseSingleRange/suffix_exceeds_size911=== PAUSE TestParseSingleRange/suffix_exceeds_size912=== RUN TestParseSingleRange/single_byte913=== PAUSE TestParseSingleRange/single_byte914=== RUN TestParseSingleRange/start_past_EOF915=== PAUSE TestParseSingleRange/start_past_EOF916=== RUN TestParseSingleRange/start_far_past_EOF917=== PAUSE TestParseSingleRange/start_far_past_EOF918=== CONT TestService_readinessHandler9192026-10-01 07:38:47.084 UTC [68684] ERROR: relation "goose_db_version" does not exist at character 369202026-10-01 07:38:47.084 UTC [68684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026/10/01 07:38:47 OK 20241026095416_initial_model.sql (393.83ms)9222026/10/01 07:38:47 OK 20251210153512_drop_unused_gin_index.sql (19.47ms)923--- PASS: TestResurrectedObjectNotDeleted (5.76s)924=== CONT TestCreatePin_ReservedPins9252026/10/01 07:38:47 OK 20251218171726_add_pins.sql (54.53ms)9262026/10/01 07:38:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57560/oidc9272026/10/01 07:38:47 OK 20260628120000_add_object_size_and_stats.sql (84.77ms)9282026/10/01 07:38:47 OK 20260905000000_add_claims.sql (140.97ms)9292026-10-01 07:38:47.955 UTC [68705] ERROR: relation "goose_db_version" does not exist at character 369302026-10-01 07:38:47.955 UTC [68705] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9312026-10-01 07:38:47.957 UTC [68713] ERROR: relation "goose_db_version" does not exist at character 369322026-10-01 07:38:47.957 UTC [68713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9332026/10/01 07:38:47 OK 20260920000000_drop_claims.sql (56.54ms)9342026-10-01 07:38:47.997 UTC [68715] ERROR: relation "goose_db_version" does not exist at character 369352026-10-01 07:38:47.997 UTC [68715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026/10/01 07:38:48 OK 20260923120000_add_pushes.sql (25.58ms)9372026/10/01 07:38:48 goose: successfully migrated database to version: 202609231200009382026/10/01 07:38:48 OK 1_commit_pending_closure.sql (2.25ms)9392026/10/01 07:38:48 OK 2_object_stats_trigger.sql (1.49ms)9402026/10/01 07:38:48 OK 3_commit_push.sql (824.38µs)9412026/10/01 07:38:48 goose: up to current file version: 39422026/10/01 07:38:48 OK 20241026095416_initial_model.sql (208.66ms)9432026/10/01 07:38:48 OK 20251210153512_drop_unused_gin_index.sql (35.57ms)9442026/10/01 07:38:48 OK 20241026095416_initial_model.sql (300.96ms)9452026/10/01 07:38:48 OK 20241026095416_initial_model.sql (313.46ms)9462026/10/01 07:38:48 OK 20251210153512_drop_unused_gin_index.sql (21.19ms)9472026/10/01 07:38:48 OK 20251210153512_drop_unused_gin_index.sql (9.63ms)9482026/10/01 07:38:48 OK 20251218171726_add_pins.sql (62.02ms)9492026/10/01 07:38:48 OK 20251218171726_add_pins.sql (22.64ms)9502026/10/01 07:38:48 OK 20251218171726_add_pins.sql (23.9ms)9512026/10/01 07:38:48 OK 20260628120000_add_object_size_and_stats.sql (62.24ms)9522026/10/01 07:38:48 OK 20260628120000_add_object_size_and_stats.sql (74.1ms)9532026/10/01 07:38:48 OK 20260628120000_add_object_size_and_stats.sql (95.49ms)954--- PASS: TestReadProxyConditionalGet (4.36s)955=== CONT TestServerTLSConfig956=== RUN TestServerTLSConfig/no_client_CA957=== PAUSE TestServerTLSConfig/no_client_CA958=== RUN TestServerTLSConfig/missing_CA_file959=== PAUSE TestServerTLSConfig/missing_CA_file960=== RUN TestServerTLSConfig/not_a_PEM_file961=== PAUSE TestServerTLSConfig/not_a_PEM_file962=== CONT TestOrphanedObjectsGC9632026/10/01 07:38:48 OK 20260905000000_add_claims.sql (61.48ms)9642026/10/01 07:38:48 OK 20260905000000_add_claims.sql (76.22ms)9652026/10/01 07:38:48 OK 20260905000000_add_claims.sql (105.03ms)9662026/10/01 07:38:48 OK 20260920000000_drop_claims.sql (92.38ms)9672026/10/01 07:38:48 OK 20260920000000_drop_claims.sql (41.13ms)9682026/10/01 07:38:48 OK 20260920000000_drop_claims.sql (48.57ms)9692026/10/01 07:38:48 OK 20260923120000_add_pushes.sql (22.91ms)9702026/10/01 07:38:48 goose: successfully migrated database to version: 202609231200009712026/10/01 07:38:48 OK 20260923120000_add_pushes.sql (22.88ms)9722026/10/01 07:38:48 goose: successfully migrated database to version: 202609231200009732026/10/01 07:38:48 OK 20260923120000_add_pushes.sql (23.54ms)9742026/10/01 07:38:48 goose: successfully migrated database to version: 202609231200009752026/10/01 07:38:48 OK 1_commit_pending_closure.sql (5.89ms)9762026/10/01 07:38:48 OK 1_commit_pending_closure.sql (3.74ms)9772026/10/01 07:38:48 OK 2_object_stats_trigger.sql (2.94ms)9782026/10/01 07:38:48 OK 2_object_stats_trigger.sql (1.87ms)9792026/10/01 07:38:48 OK 1_commit_pending_closure.sql (6.4ms)9802026/10/01 07:38:48 OK 3_commit_push.sql (1.77ms)9812026/10/01 07:38:48 goose: up to current file version: 39822026/10/01 07:38:48 OK 3_commit_push.sql (1.9ms)9832026/10/01 07:38:48 goose: up to current file version: 39842026/10/01 07:38:48 OK 2_object_stats_trigger.sql (1.41ms)9852026/10/01 07:38:48 OK 3_commit_push.sql (554.33µs)9862026/10/01 07:38:48 goose: up to current file version: 3987--- PASS: TestReadProxyHead (4.34s)988=== CONT TestObjectStatsTrigger989--- PASS: TestReadProxy404 (4.09s)990=== CONT TestMultipartCleanup991--- PASS: TestReadProxyInvalidPath (4.85s)992=== CONT TestSkippedUploadsHandler9932026/10/01 07:38:49 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000994--- PASS: TestSkippedUploadsHandler (0.00s)995=== CONT TestClientFallsBackToClosures9962026-10-01 07:38:50.442 UTC [68751] ERROR: relation "goose_db_version" does not exist at character 369972026-10-01 07:38:50.442 UTC [68751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026-10-01 07:38:50.482 UTC [68750] ERROR: relation "goose_db_version" does not exist at character 369992026-10-01 07:38:50.482 UTC [68750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10002026-10-01 07:38:50.677 UTC [68755] ERROR: relation "goose_db_version" does not exist at character 3610012026-10-01 07:38:50.677 UTC [68755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10022026/10/01 07:38:50 OK 20241026095416_initial_model.sql (253.59ms)10032026/10/01 07:38:50 OK 20241026095416_initial_model.sql (172.2ms)10042026/10/01 07:38:50 OK 20251210153512_drop_unused_gin_index.sql (12.86ms)10052026/10/01 07:38:50 OK 20251210153512_drop_unused_gin_index.sql (13.37ms)10062026/10/01 07:38:50 OK 20251218171726_add_pins.sql (53.1ms)10072026/10/01 07:38:50 OK 20251218171726_add_pins.sql (62.05ms)10082026/10/01 07:38:50 OK 20260628120000_add_object_size_and_stats.sql (55.24ms)10092026-10-01 07:38:50.944 UTC [68759] ERROR: relation "goose_db_version" does not exist at character 3610102026-10-01 07:38:50.944 UTC [68759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10112026/10/01 07:38:50 OK 20260628120000_add_object_size_and_stats.sql (67.8ms)10122026/10/01 07:38:51 OK 20260905000000_add_claims.sql (183.28ms)10132026/10/01 07:38:51 OK 20260905000000_add_claims.sql (205.34ms)10142026-10-01 07:38:51.139 UTC [68761] ERROR: relation "goose_db_version" does not exist at character 3610152026-10-01 07:38:51.139 UTC [68761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10162026/10/01 07:38:51 OK 20260920000000_drop_claims.sql (91.5ms)10172026/10/01 07:38:51 OK 20260920000000_drop_claims.sql (103.02ms)10182026/10/01 07:38:51 OK 20241026095416_initial_model.sql (426.28ms)10192026/10/01 07:38:51 OK 20260923120000_add_pushes.sql (33.25ms)10202026/10/01 07:38:51 goose: successfully migrated database to version: 2026092312000010212026/10/01 07:38:51 OK 20251210153512_drop_unused_gin_index.sql (23.41ms)10222026/10/01 07:38:51 OK 20260923120000_add_pushes.sql (25.82ms)10232026/10/01 07:38:51 goose: successfully migrated database to version: 2026092312000010242026/10/01 07:38:51 OK 1_commit_pending_closure.sql (4.45ms)10252026/10/01 07:38:51 OK 1_commit_pending_closure.sql (3.35ms)10262026/10/01 07:38:51 OK 2_object_stats_trigger.sql (3.52ms)10272026/10/01 07:38:51 OK 2_object_stats_trigger.sql (10.07ms)10282026/10/01 07:38:51 OK 3_commit_push.sql (9.06ms)10292026/10/01 07:38:51 goose: up to current file version: 310302026/10/01 07:38:51 OK 3_commit_push.sql (2.89ms)10312026/10/01 07:38:51 goose: up to current file version: 310322026/10/01 07:38:51 OK 20251218171726_add_pins.sql (42.53ms)10332026/10/01 07:38:51 OK 20260628120000_add_object_size_and_stats.sql (49.21ms)10342026/10/01 07:38:51 OK 20260905000000_add_claims.sql (132.91ms)10352026/10/01 07:38:51 OK 20241026095416_initial_model.sql (403.83ms)10362026/10/01 07:38:51 OK 20251210153512_drop_unused_gin_index.sql (9.62ms)10372026/10/01 07:38:51 OK 20260920000000_drop_claims.sql (143.49ms)10382026/10/01 07:38:51 OK 20251218171726_add_pins.sql (85.53ms)10392026/10/01 07:38:51 OK 20260923120000_add_pushes.sql (41.88ms)10402026/10/01 07:38:51 goose: successfully migrated database to version: 2026092312000010412026/10/01 07:38:51 OK 1_commit_pending_closure.sql (1.7ms)10422026/10/01 07:38:51 OK 2_object_stats_trigger.sql (522.08µs)10432026/10/01 07:38:51 OK 3_commit_push.sql (1.74ms)10442026/10/01 07:38:51 goose: up to current file version: 310452026/10/01 07:38:51 OK 20260628120000_add_object_size_and_stats.sql (78.9ms)10462026/10/01 07:38:51 OK 20241026095416_initial_model.sql (447.09ms)10472026/10/01 07:38:51 OK 20251210153512_drop_unused_gin_index.sql (38.28ms)10482026/10/01 07:38:51 OK 20251218171726_add_pins.sql (82.17ms)1049--- PASS: TestReadProxyNarStreaming (6.06s)1050=== CONT TestGCTaskStore_GetReturnsLatest1051--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1052=== CONT TestGCTaskStore_GetEmpty1053--- PASS: TestGCTaskStore_GetEmpty (0.00s)1054=== CONT TestGCTaskStore_ConflictDifferentParams1055--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1056=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT10572026/10/01 07:38:51 OK 20260905000000_add_claims.sql (204.53ms)10582026/10/01 07:38:51 OK 20260628120000_add_object_size_and_stats.sql (105.01ms)10592026/10/01 07:38:52 OK 20260920000000_drop_claims.sql (113.78ms)10602026/10/01 07:38:52 OK 20260923120000_add_pushes.sql (40.27ms)10612026/10/01 07:38:52 goose: successfully migrated database to version: 2026092312000010622026/10/01 07:38:52 OK 1_commit_pending_closure.sql (2.47ms)10632026/10/01 07:38:52 OK 2_object_stats_trigger.sql (623.21µs)10642026/10/01 07:38:52 OK 3_commit_push.sql (455.29µs)10652026/10/01 07:38:52 goose: up to current file version: 310662026/10/01 07:38:52 OK 20260905000000_add_claims.sql (199.33ms)10672026/10/01 07:38:52 OK 20260920000000_drop_claims.sql (139.55ms)10682026/10/01 07:38:52 OK 20260923120000_add_pushes.sql (37.21ms)10692026/10/01 07:38:52 goose: successfully migrated database to version: 2026092312000010702026/10/01 07:38:52 OK 1_commit_pending_closure.sql (2.12ms)10712026/10/01 07:38:52 OK 2_object_stats_trigger.sql (609.17µs)10722026/10/01 07:38:52 OK 3_commit_push.sql (424.63µs)10732026/10/01 07:38:52 goose: up to current file version: 31074--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.21s)1075=== CONT TestCompleteMultipartUnregistered1076--- PASS: TestReadProxyNarinfo (6.25s)1077=== CONT TestService_verifyS3Integrity10782026-10-01 07:38:52.972 UTC [68773] ERROR: relation "goose_db_version" does not exist at character 3610792026-10-01 07:38:52.972 UTC [68773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10802026/10/01 07:38:53 WARN readiness check failed error="closed pool"1081--- PASS: TestService_readinessHandler (6.24s)1082=== CONT TestService_createPendingClosureHandler10832026/10/01 07:38:53 OK 20241026095416_initial_model.sql (528.98ms)10842026/10/01 07:38:53 OK 20251210153512_drop_unused_gin_index.sql (8.04ms)10852026/10/01 07:38:53 OK 20251218171726_add_pins.sql (90.42ms)10862026/10/01 07:38:53 OK 20260628120000_add_object_size_and_stats.sql (75.93ms)10872026/10/01 07:38:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10882026/10/01 07:38:53 WARN Refused reserved pin name=worker-x86_64-linux10892026/10/01 07:38:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10902026/10/01 07:38:53 INFO Received create pin request method=POST path=/api/pins/my-app10912026/10/01 07:38:53 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1092--- PASS: TestCreatePin_ReservedPins (6.17s)1093=== CONT TestProxyHeadersOnlyTrustedOnSocket10942026/10/01 07:38:54 OK 20260905000000_add_claims.sql (177.73ms)10952026/10/01 07:38:54 OK 20260920000000_drop_claims.sql (107.07ms)10962026/10/01 07:38:54 OK 20260923120000_add_pushes.sql (22.61ms)10972026/10/01 07:38:54 goose: successfully migrated database to version: 2026092312000010982026/10/01 07:38:54 OK 1_commit_pending_closure.sql (1.37ms)10992026/10/01 07:38:54 OK 2_object_stats_trigger.sql (316.04µs)11002026/10/01 07:38:54 OK 3_commit_push.sql (266.04µs)11012026/10/01 07:38:54 goose: up to current file version: 311022026-10-01 07:38:54.327 UTC [68829] ERROR: relation "goose_db_version" does not exist at character 3611032026-10-01 07:38:54.327 UTC [68829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026-10-01 07:38:54.719 UTC [68834] ERROR: relation "goose_db_version" does not exist at character 3611052026-10-01 07:38:54.719 UTC [68834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11062026/10/01 07:38:54 OK 20241026095416_initial_model.sql (435.85ms)11072026/10/01 07:38:54 OK 20251210153512_drop_unused_gin_index.sql (28.2ms)11082026/10/01 07:38:54 OK 20251218171726_add_pins.sql (60.26ms)11092026/10/01 07:38:55 OK 20260628120000_add_object_size_and_stats.sql (37.59ms)11102026/10/01 07:38:55 OK 20241026095416_initial_model.sql (277.62ms)11112026/10/01 07:38:55 OK 20251210153512_drop_unused_gin_index.sql (20.74ms)11122026/10/01 07:38:55 OK 20260905000000_add_claims.sql (162.92ms)11132026/10/01 07:38:55 OK 20251218171726_add_pins.sql (57.28ms)11142026/10/01 07:38:55 OK 20260920000000_drop_claims.sql (77.15ms)11152026-10-01 07:38:55.260 UTC [68838] ERROR: relation "goose_db_version" does not exist at character 3611162026-10-01 07:38:55.260 UTC [68838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026/10/01 07:38:55 OK 20260628120000_add_object_size_and_stats.sql (59.32ms)11182026/10/01 07:38:55 OK 20260923120000_add_pushes.sql (25.23ms)11192026/10/01 07:38:55 goose: successfully migrated database to version: 2026092312000011202026/10/01 07:38:55 OK 1_commit_pending_closure.sql (909.38µs)11212026/10/01 07:38:55 OK 2_object_stats_trigger.sql (218.75µs)11222026/10/01 07:38:55 OK 3_commit_push.sql (187.21µs)11232026/10/01 07:38:55 goose: up to current file version: 311242026/10/01 07:38:55 OK 20260905000000_add_claims.sql (145.34ms)11252026/10/01 07:38:55 OK 20260920000000_drop_claims.sql (77.96ms)11262026/10/01 07:38:55 OK 20260923120000_add_pushes.sql (42.27ms)11272026/10/01 07:38:55 goose: successfully migrated database to version: 2026092312000011282026/10/01 07:38:55 OK 1_commit_pending_closure.sql (936.79µs)11292026/10/01 07:38:55 OK 2_object_stats_trigger.sql (241.54µs)11302026/10/01 07:38:55 OK 3_commit_push.sql (179.58µs)11312026/10/01 07:38:55 goose: up to current file version: 311322026/10/01 07:38:55 OK 20241026095416_initial_model.sql (402.41ms)11332026/10/01 07:38:55 OK 20251210153512_drop_unused_gin_index.sql (8.64ms)1134--- PASS: TestObjectStatsTrigger (6.74s)1135=== CONT TestService_cleanupPendingClosuresHandler11362026/10/01 07:38:55 OK 20251218171726_add_pins.sql (67.25ms)1137=== NAME TestOrphanedObjectsGC1138 orphaned_objects_gc_test.go:290: GC Test Summary:1139 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1140 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1141 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1142 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1143 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1144--- PASS: TestOrphanedObjectsGC (7.44s)1145=== CONT TestUploadHandlersRejectOversizedBody1146=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1147=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1148=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1149=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1150=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1151=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1152=== CONT TestUploadHandlersRejectInvalidKeys1153=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1154=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1155=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1156=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1157=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1158=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1159=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1160=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1161=== CONT TestDeduplicatedObjectsRecordedAsPending11622026/10/01 07:38:55 OK 20260628120000_add_object_size_and_stats.sql (75.77ms)11632026/10/01 07:38:56 OK 20260905000000_add_claims.sql (130.44ms)11642026/10/01 07:38:56 INFO Received uploads request method=POST path=/api/pending_closures11652026/10/01 07:38:56 OK 20260920000000_drop_claims.sql (125.8ms)11662026/10/01 07:38:56 OK 20260923120000_add_pushes.sql (46.27ms)11672026/10/01 07:38:56 goose: successfully migrated database to version: 2026092312000011682026/10/01 07:38:56 OK 1_commit_pending_closure.sql (2.1ms)11692026/10/01 07:38:56 OK 2_object_stats_trigger.sql (328µs)11702026/10/01 07:38:56 OK 3_commit_push.sql (279.75µs)11712026/10/01 07:38:56 goose: up to current file version: 311722026/10/01 07:38:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11732026/10/01 07:38:56 INFO Aborted multipart uploads count=11174--- PASS: TestMultipartCleanup (6.94s)1175=== CONT TestGCTaskStore_StartNew1176--- PASS: TestGCTaskStore_StartNew (0.00s)1177=== CONT TestIsValidUploadKey1178=== RUN TestIsValidUploadKey/narinfo1179=== PAUSE TestIsValidUploadKey/narinfo1180=== RUN TestIsValidUploadKey/nar_zst1181=== PAUSE TestIsValidUploadKey/nar_zst1182=== RUN TestIsValidUploadKey/nar_xz1183=== PAUSE TestIsValidUploadKey/nar_xz1184=== RUN TestIsValidUploadKey/nar_plain1185=== PAUSE TestIsValidUploadKey/nar_plain1186=== RUN TestIsValidUploadKey/listing1187=== PAUSE TestIsValidUploadKey/listing1188=== RUN TestIsValidUploadKey/build_log1189=== PAUSE TestIsValidUploadKey/build_log1190=== RUN TestIsValidUploadKey/build_log_home-manager_file1191=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1192=== RUN TestIsValidUploadKey/build_log_plus_in_name1193=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1194=== RUN TestIsValidUploadKey/build_log_question_mark1195=== PAUSE TestIsValidUploadKey/build_log_question_mark1196=== RUN TestIsValidUploadKey/build_log_equals1197=== PAUSE TestIsValidUploadKey/build_log_equals1198=== RUN TestIsValidUploadKey/realisation1199=== PAUSE TestIsValidUploadKey/realisation1200=== RUN TestIsValidUploadKey/realisation_plus_in_output1201=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1202=== RUN TestIsValidUploadKey/nix-cache-info1203=== PAUSE TestIsValidUploadKey/nix-cache-info1204=== RUN TestIsValidUploadKey/index.html1205=== PAUSE TestIsValidUploadKey/index.html1206=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1207=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1208=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1209=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1210=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1211=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1212=== RUN TestIsValidUploadKey/traversal1213=== PAUSE TestIsValidUploadKey/traversal1214=== RUN TestIsValidUploadKey/traversal_nar1215=== PAUSE TestIsValidUploadKey/traversal_nar1216=== RUN TestIsValidUploadKey/absolute1217=== PAUSE TestIsValidUploadKey/absolute1218=== RUN TestIsValidUploadKey/empty_key1219=== PAUSE TestIsValidUploadKey/empty_key1220=== RUN TestIsValidUploadKey/unknown_type1221=== PAUSE TestIsValidUploadKey/unknown_type1222=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12232026-10-01 07:38:56.769 UTC [68859] ERROR: relation "goose_db_version" does not exist at character 3612242026-10-01 07:38:56.769 UTC [68859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1225=== NAME TestOrphanedObjectsGCStressTest1226 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1227 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion12282026/10/01 07:38:57 OK 20241026095416_initial_model.sql (458.8ms)12292026/10/01 07:38:57 OK 20251210153512_drop_unused_gin_index.sql (30.02ms)12302026/10/01 07:38:57 OK 20251218171726_add_pins.sql (26.19ms)12312026-10-01 07:38:57.456 UTC [68867] ERROR: relation "goose_db_version" does not exist at character 3612322026-10-01 07:38:57.456 UTC [68867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/10/01 07:38:57 OK 20260628120000_add_object_size_and_stats.sql (40.69ms)12342026/10/01 07:38:57 OK 20260905000000_add_claims.sql (74.41ms)12352026/10/01 07:38:57 OK 20260920000000_drop_claims.sql (10.21ms)12362026-10-01 07:38:57.546 UTC [68871] ERROR: relation "goose_db_version" does not exist at character 3612372026-10-01 07:38:57.546 UTC [68871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12382026/10/01 07:38:57 OK 20260923120000_add_pushes.sql (12.62ms)12392026/10/01 07:38:57 goose: successfully migrated database to version: 2026092312000012402026/10/01 07:38:57 OK 1_commit_pending_closure.sql (944.58µs)12412026/10/01 07:38:57 OK 2_object_stats_trigger.sql (243.96µs)12422026/10/01 07:38:57 OK 3_commit_push.sql (180.54µs)12432026/10/01 07:38:57 goose: up to current file version: 312442026-10-01 07:38:57.694 UTC [68878] ERROR: relation "goose_db_version" does not exist at character 3612452026-10-01 07:38:57.694 UTC [68878] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/10/01 07:38:57 INFO Received uploads request method=POST path=/api/pending_closures12472026/10/01 07:38:57 OK 20241026095416_initial_model.sql (231.23ms)12482026/10/01 07:38:57 OK 20251210153512_drop_unused_gin_index.sql (9.13ms)12492026/10/01 07:38:57 OK 20241026095416_initial_model.sql (189.96ms)12502026/10/01 07:38:57 OK 20251210153512_drop_unused_gin_index.sql (9.66ms)12512026/10/01 07:38:57 INFO Received uploads request method=POST path=/api/pending_closures12522026/10/01 07:38:57 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12532026/10/01 07:38:57 INFO Uploading p65hgbjjqziw73622rm9wz15ba1v2b56-shared-dep (136B)12542026/10/01 07:38:57 INFO Uploading g8i8dl36xww1dqh6jjpryqjkz02543za-a (248B)12552026/10/01 07:38:57 INFO Received uploads request method=POST path=/api/pending_closures12562026/10/01 07:38:57 WARN Failed to register uploaded object key=810wqz2a66mwh7blpz501m3hk4b8cd6g.ls error="server returned 404: 404 page not found\n"12572026/10/01 07:38:57 OK 20251218171726_add_pins.sql (59.05ms)12582026/10/01 07:38:57 OK 20251218171726_add_pins.sql (32.17ms)12592026/10/01 07:38:57 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12602026/10/01 07:38:57 WARN Failed to register uploaded object key=g8i8dl36xww1dqh6jjpryqjkz02543za.ls error="server returned 404: 404 page not found\n"12612026/10/01 07:38:57 WARN Failed to register uploaded object key=p65hgbjjqziw73622rm9wz15ba1v2b56.ls error="server returned 404: 404 page not found\n"12622026/10/01 07:38:57 WARN Failed to register uploaded object key=nar/0ra9f4i9fhgqypwbbr9z1z0ix9aqjym15nwg4ywx2ii6aq65qmfa.nar.zst error="server returned 404: 404 page not found\n"12632026/10/01 07:38:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12642026/10/01 07:38:57 INFO Signed narinfos id=2 count=212652026/10/01 07:38:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12662026/10/01 07:38:57 INFO Signed narinfos id=1 count=212672026/10/01 07:38:57 INFO Uploading 4 narinfos12682026/10/01 07:38:57 OK 20260628120000_add_object_size_and_stats.sql (56.46ms)12692026/10/01 07:38:57 WARN Failed to register uploaded object key=p65hgbjjqziw73622rm9wz15ba1v2b56.narinfo error="server returned 404: 404 page not found\n"12702026/10/01 07:38:57 WARN Failed to register uploaded object key=810wqz2a66mwh7blpz501m3hk4b8cd6g.narinfo error="server returned 404: 404 page not found\n"12712026/10/01 07:38:57 WARN Failed to register uploaded object key=g8i8dl36xww1dqh6jjpryqjkz02543za.narinfo error="server returned 404: 404 page not found\n"12722026/10/01 07:38:57 OK 20260628120000_add_object_size_and_stats.sql (67.46ms)1273--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (6.10s)1274=== CONT TestGCSweepDeliversEachKeyOnce12752026-10-01 07:38:57.964 UTC [68886] ERROR: relation "goose_db_version" does not exist at character 3612762026-10-01 07:38:57.964 UTC [68886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/10/01 07:38:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12782026/10/01 07:38:57 WARN Failed to register uploaded object key=p65hgbjjqziw73622rm9wz15ba1v2b56.narinfo error="server returned 404: 404 page not found\n"12792026/10/01 07:38:58 OK 20241026095416_initial_model.sql (243.94ms)12802026/10/01 07:38:58 OK 20251210153512_drop_unused_gin_index.sql (13.62ms)12812026/10/01 07:38:58 INFO Completed upload id=112822026/10/01 07:38:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12832026/10/01 07:38:58 OK 20260905000000_add_claims.sql (96.21ms)12842026/10/01 07:38:58 INFO Completed upload id=212852026/10/01 07:38:58 INFO Upload complete. (295ms)1286=== NAME TestClientFallsBackToClosures1287 client_pushes_test.go:112: Retrieved narinfo from S3:1288 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientFallsBackToClosures3590338838/001/store/p65hgbjjqziw73622rm9wz15ba1v2b56-shared-dep1289 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1290 Compression: zstd1291 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821292 NarSize: 1361293 References: 1294 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1295 client_pushes_test.go:112: Retrieved narinfo from S3:1296 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientFallsBackToClosures3590338838/001/store/g8i8dl36xww1dqh6jjpryqjkz02543za-a1297 URL: nar/0ra9f4i9fhgqypwbbr9z1z0ix9aqjym15nwg4ywx2ii6aq65qmfa.nar.zst1298 Compression: zstd1299 NarHash: sha256:0ra9f4i9fhgqypwbbr9z1z0ix9aqjym15nwg4ywx2ii6aq65qmfa1300 NarSize: 2481301 References: /nix/var/nix/builds/nix-67309-3657216313/TestClientFallsBackToClosures3590338838/001/store/p65hgbjjqziw73622rm9wz15ba1v2b56-shared-dep1302 CA: text:sha256:0si7r0d2imhvrd165d3i16dpmzxl646x25q47i01949sfy8rgby613032026/10/01 07:38:58 OK 20260905000000_add_claims.sql (108.42ms)1304 client_pushes_test.go:112: Retrieved narinfo from S3:1305 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientFallsBackToClosures3590338838/001/store/810wqz2a66mwh7blpz501m3hk4b8cd6g-b1306 URL: nar/0ra9f4i9fhgqypwbbr9z1z0ix9aqjym15nwg4ywx2ii6aq65qmfa.nar.zst1307 Compression: zstd1308 NarHash: sha256:0ra9f4i9fhgqypwbbr9z1z0ix9aqjym15nwg4ywx2ii6aq65qmfa1309 NarSize: 2481310 References: /nix/var/nix/builds/nix-67309-3657216313/TestClientFallsBackToClosures3590338838/001/store/p65hgbjjqziw73622rm9wz15ba1v2b56-shared-dep1311 CA: text:sha256:0si7r0d2imhvrd165d3i16dpmzxl646x25q47i01949sfy8rgby613122026/10/01 07:38:58 OK 20251218171726_add_pins.sql (31.41ms)13132026/10/01 07:38:58 OK 20260920000000_drop_claims.sql (58.91ms)13142026/10/01 07:38:58 OK 20260920000000_drop_claims.sql (57.99ms)13152026/10/01 07:38:58 OK 20260628120000_add_object_size_and_stats.sql (55.39ms)1316--- PASS: TestClientFallsBackToClosures (8.19s)1317=== CONT TestTombstonedObjectOfferedWithoutWaiting13182026/10/01 07:38:58 OK 20260923120000_add_pushes.sql (32.84ms)13192026/10/01 07:38:58 goose: successfully migrated database to version: 2026092312000013202026/10/01 07:38:58 OK 20260923120000_add_pushes.sql (34.28ms)13212026/10/01 07:38:58 goose: successfully migrated database to version: 2026092312000013222026/10/01 07:38:58 OK 1_commit_pending_closure.sql (1.87ms)13232026/10/01 07:38:58 OK 1_commit_pending_closure.sql (1.62ms)13242026/10/01 07:38:58 OK 2_object_stats_trigger.sql (232.83µs)13252026/10/01 07:38:58 OK 2_object_stats_trigger.sql (227.33µs)13262026/10/01 07:38:58 OK 3_commit_push.sql (168.63µs)13272026/10/01 07:38:58 goose: up to current file version: 313282026/10/01 07:38:58 OK 3_commit_push.sql (201.54µs)13292026/10/01 07:38:58 goose: up to current file version: 313302026/10/01 07:38:58 OK 20260905000000_add_claims.sql (90.26ms)13312026/10/01 07:38:58 OK 20260920000000_drop_claims.sql (42.38ms)13322026/10/01 07:38:58 OK 20260923120000_add_pushes.sql (22.96ms)13332026/10/01 07:38:58 goose: successfully migrated database to version: 2026092312000013342026/10/01 07:38:58 OK 1_commit_pending_closure.sql (1.04ms)13352026/10/01 07:38:58 OK 2_object_stats_trigger.sql (247.46µs)13362026/10/01 07:38:58 OK 3_commit_push.sql (242.67µs)13372026/10/01 07:38:58 goose: up to current file version: 313382026/10/01 07:38:58 OK 20241026095416_initial_model.sql (274.15ms)13392026/10/01 07:38:58 OK 20251210153512_drop_unused_gin_index.sql (11.13ms)13402026/10/01 07:38:58 OK 20251218171726_add_pins.sql (58.27ms)13412026/10/01 07:38:58 INFO Received uploads request method=POST path=/api/pending_closures13422026/10/01 07:38:58 OK 20260628120000_add_object_size_and_stats.sql (54.62ms)13432026/10/01 07:38:58 OK 20260905000000_add_claims.sql (118.54ms)13442026/10/01 07:38:58 OK 20260920000000_drop_claims.sql (82.22ms)13452026/10/01 07:38:58 OK 20260923120000_add_pushes.sql (38.65ms)13462026/10/01 07:38:58 goose: successfully migrated database to version: 2026092312000013472026/10/01 07:38:58 OK 1_commit_pending_closure.sql (1.58ms)13482026/10/01 07:38:58 OK 2_object_stats_trigger.sql (285µs)13492026/10/01 07:38:58 OK 3_commit_push.sql (183.71µs)13502026/10/01 07:38:58 goose: up to current file version: 313512026/10/01 07:38:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13522026/10/01 07:38:58 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1353--- PASS: TestCompleteMultipartUnregistered (6.45s)1354=== CONT TestGCTaskStore_DeduplicateSameParams1355--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1356=== CONT TestGCSweepSkipsPendingObjects13572026/10/01 07:38:59 INFO Received uploads request method=POST path=/api/pending_closures13582026/10/01 07:38:59 INFO Received uploads request method=POST path=/api/pending_closures13592026/10/01 07:38:59 INFO Received uploads request method=POST path=/api/pending_closures13602026/10/01 07:38:59 INFO Starting HTTP server address=127.0.0.1:5770913612026/10/01 07:38:59 INFO Starting HTTP server address=/nix/var/nix/builds/nix-67309-3657216313/TestProxyHeadersOnlyTrustedOnSocket419783057/001/proxy.sock13622026/10/01 07:38:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13632026/10/01 07:38:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1364--- PASS: TestProxyHeadersOnlyTrustedOnSocket (5.88s)1365=== CONT TestPushDedupSurvivesConcurrentGC13662026-10-01 07:39:00.276 UTC [68932] ERROR: relation "goose_db_version" does not exist at character 3613672026-10-01 07:39:00.276 UTC [68932] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13682026-10-01 07:39:00.483 UTC [68940] ERROR: relation "goose_db_version" does not exist at character 3613692026-10-01 07:39:00.483 UTC [68940] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13702026-10-01 07:39:00.675 UTC [68945] ERROR: relation "goose_db_version" does not exist at character 3613712026-10-01 07:39:00.675 UTC [68945] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13722026/10/01 07:39:00 OK 20241026095416_initial_model.sql (316.93ms)13732026/10/01 07:39:00 OK 20251210153512_drop_unused_gin_index.sql (21.79ms)13742026/10/01 07:39:00 OK 20251218171726_add_pins.sql (67.06ms)13752026/10/01 07:39:00 OK 20260628120000_add_object_size_and_stats.sql (77.82ms)13762026/10/01 07:39:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13772026/10/01 07:39:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTEzOTQxOWEtNzkzNC00YmRiLTk2YmYtOWZiMjY5ZTIzMjg5LjJmNTQ0MzUzLTBiMjktNGVjYy1hMjJkLTExY2U2ZDQwMzc3MHgxNzkwODQwMzM4NDk4OTcwMDAw parts=1013782026/10/01 07:39:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13792026/10/01 07:39:00 OK 20260905000000_add_claims.sql (150.86ms)13802026/10/01 07:39:01 OK 20241026095416_initial_model.sql (393.39ms)13812026/10/01 07:39:01 INFO Completed upload id=113822026/10/01 07:39:01 INFO Received uploads request method=POST path=/api/pending_closures13832026/10/01 07:39:01 INFO Received uploads request method=POST path=/api/pending_closures13842026/10/01 07:39:01 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13852026/10/01 07:39:01 WARN Found objects in DB but missing from S3, will re-upload count=11386--- PASS: TestService_verifyS3Integrity (8.13s)1387=== CONT TestLeadElectsOneAndHandsOver13882026/10/01 07:39:01 OK 20251210153512_drop_unused_gin_index.sql (25.28ms)13892026/10/01 07:39:01 OK 20251218171726_add_pins.sql (58.17ms)13902026/10/01 07:39:01 OK 20260920000000_drop_claims.sql (119.36ms)13912026/10/01 07:39:01 OK 20260923120000_add_pushes.sql (38.22ms)13922026/10/01 07:39:01 goose: successfully migrated database to version: 2026092312000013932026/10/01 07:39:01 OK 1_commit_pending_closure.sql (1.66ms)13942026/10/01 07:39:01 OK 20260628120000_add_object_size_and_stats.sql (63.75ms)13952026/10/01 07:39:01 OK 2_object_stats_trigger.sql (230.92µs)13962026/10/01 07:39:01 OK 3_commit_push.sql (203.67µs)13972026/10/01 07:39:01 goose: up to current file version: 313982026/10/01 07:39:01 OK 20241026095416_initial_model.sql (418.72ms)13992026/10/01 07:39:01 OK 20251210153512_drop_unused_gin_index.sql (17.13ms)14002026/10/01 07:39:01 OK 20260905000000_add_claims.sql (106.1ms)14012026/10/01 07:39:01 OK 20251218171726_add_pins.sql (52.85ms)14022026/10/01 07:39:01 OK 20260920000000_drop_claims.sql (91.12ms)14032026/10/01 07:39:01 OK 20260628120000_add_object_size_and_stats.sql (87.55ms)14042026/10/01 07:39:01 OK 20260923120000_add_pushes.sql (33.61ms)14052026/10/01 07:39:01 goose: successfully migrated database to version: 2026092312000014062026/10/01 07:39:01 OK 1_commit_pending_closure.sql (1.23ms)14072026/10/01 07:39:01 OK 2_object_stats_trigger.sql (269.79µs)14082026/10/01 07:39:01 OK 3_commit_push.sql (242.54µs)14092026/10/01 07:39:01 goose: up to current file version: 314102026/10/01 07:39:01 OK 20260905000000_add_claims.sql (134.83ms)14112026/10/01 07:39:01 INFO Received cleanup request method=DELETE path=/api/pending_closures14122026/10/01 07:39:01 INFO Aborted multipart uploads count=014132026/10/01 07:39:01 INFO Received uploads request method=POST path=/api/pending_closures14142026/10/01 07:39:01 OK 20260920000000_drop_claims.sql (69.46ms)14152026/10/01 07:39:01 OK 20260923120000_add_pushes.sql (42.92ms)14162026/10/01 07:39:01 goose: successfully migrated database to version: 2026092312000014172026/10/01 07:39:01 OK 1_commit_pending_closure.sql (2.57ms)14182026/10/01 07:39:01 OK 2_object_stats_trigger.sql (633.63µs)14192026/10/01 07:39:01 OK 3_commit_push.sql (382.71µs)14202026/10/01 07:39:01 goose: up to current file version: 314212026/10/01 07:39:01 INFO Received cleanup request method=DELETE path=/api/pending_closures14222026/10/01 07:39:01 INFO Aborted multipart uploads count=114232026/10/01 07:39:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14242026-10-01 07:39:01.696 UTC [68932] ERROR: Closure does not exist: id=114252026-10-01 07:39:01.696 UTC [68932] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE14262026-10-01 07:39:01.696 UTC [68932] STATEMENT: -- name: CommitPendingClosure :exec1427 SELECT commit_pending_closure($1::bigint)1428 1429--- PASS: TestService_cleanupPendingClosuresHandler (5.86s)1430=== CONT TestResolveDBConnectionString1431=== RUN TestResolveDBConnectionString/flag_wins1432=== PAUSE TestResolveDBConnectionString/flag_wins1433=== RUN TestResolveDBConnectionString/file_when_flag_empty1434=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1435=== RUN TestResolveDBConnectionString/missing_file_is_an_error1436=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1437=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1438=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1439=== RUN TestResolveDBConnectionString/nothing_configured1440=== PAUSE TestResolveDBConnectionString/nothing_configured1441=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14422026/10/01 07:39:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14432026/10/01 07:39:01 INFO Received uploads request method=POST path=/api/pending_closures1444--- PASS: TestDeduplicatedObjectsRecordedAsPending (6.10s)1445=== CONT TestGCMetrics14462026/10/01 07:39:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTEzOTQxOWEtNzkzNC00YmRiLTk2YmYtOWZiMjY5ZTIzMjg5LjU5NGFlNjQ1LWVkYzktNDYxYS05MzA3LWQ2NzE2YzdhMmRiY3gxNzkwODQwMzM5NDE1MTMxMDAw parts=1014472026/10/01 07:39:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14482026/10/01 07:39:02 INFO Completed upload id=114492026/10/01 07:39:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014502026/10/01 07:39:02 INFO Received uploads request method=POST path=/api/pending_closures14512026/10/01 07:39:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures14522026/10/01 07:39:02 INFO Aborted multipart uploads count=014532026/10/01 07:39:02 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=014542026/10/01 07:39:02 INFO Vacuumed table table=pending_closures14552026/10/01 07:39:02 INFO Vacuumed table table=pending_objects14562026/10/01 07:39:02 INFO Vacuumed table table=multipart_uploads14572026/10/01 07:39:02 INFO Received uploads request method=POST path=/api/pending_closures14582026/10/01 07:39:02 INFO Vacuumed table table=closures14592026/10/01 07:39:02 INFO Vacuumed table table=objects14602026/10/01 07:39:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001461--- PASS: TestService_createPendingClosureHandler (9.15s)1462=== CONT TestLeadEndsOnShutdown1463--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.17s)1464=== CONT TestProxyWriteTimeout1465=== RUN TestProxyWriteTimeout/narinfo1466=== PAUSE TestProxyWriteTimeout/narinfo1467=== RUN TestProxyWriteTimeout/1_GiB_nar1468=== PAUSE TestProxyWriteTimeout/1_GiB_nar1469=== RUN TestProxyWriteTimeout/10_GiB_nar1470=== PAUSE TestProxyWriteTimeout/10_GiB_nar1471=== RUN TestProxyWriteTimeout/unknown_size1472=== PAUSE TestProxyWriteTimeout/unknown_size1473=== CONT TestClientCADerivations14742026-10-01 07:39:02.915 UTC [68988] ERROR: relation "goose_db_version" does not exist at character 3614752026-10-01 07:39:02.915 UTC [68988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026-10-01 07:39:02.924 UTC [68990] ERROR: relation "goose_db_version" does not exist at character 3614772026-10-01 07:39:02.924 UTC [68990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14782026/10/01 07:39:03 OK 20241026095416_initial_model.sql (251.43ms)14792026/10/01 07:39:03 OK 20241026095416_initial_model.sql (250.84ms)14802026/10/01 07:39:03 OK 20251210153512_drop_unused_gin_index.sql (18.79ms)14812026/10/01 07:39:03 OK 20251210153512_drop_unused_gin_index.sql (9.96ms)14822026/10/01 07:39:03 OK 20251218171726_add_pins.sql (31.74ms)14832026/10/01 07:39:03 OK 20251218171726_add_pins.sql (60.68ms)14842026/10/01 07:39:03 OK 20260628120000_add_object_size_and_stats.sql (83.35ms)14852026/10/01 07:39:03 OK 20260628120000_add_object_size_and_stats.sql (63.21ms)14862026-10-01 07:39:03.398 UTC [69010] ERROR: relation "goose_db_version" does not exist at character 3614872026-10-01 07:39:03.398 UTC [69010] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14882026/10/01 07:39:03 OK 20260905000000_add_claims.sql (93.8ms)14892026/10/01 07:39:03 OK 20260905000000_add_claims.sql (105.33ms)14902026/10/01 07:39:03 OK 20260920000000_drop_claims.sql (54.24ms)14912026/10/01 07:39:03 OK 20260920000000_drop_claims.sql (54.35ms)14922026/10/01 07:39:03 OK 20260923120000_add_pushes.sql (32.9ms)14932026/10/01 07:39:03 goose: successfully migrated database to version: 2026092312000014942026/10/01 07:39:03 OK 1_commit_pending_closure.sql (919.67µs)14952026/10/01 07:39:03 OK 2_object_stats_trigger.sql (208.88µs)14962026/10/01 07:39:03 OK 3_commit_push.sql (184.96µs)14972026/10/01 07:39:03 goose: up to current file version: 314982026/10/01 07:39:03 OK 20260923120000_add_pushes.sql (23.32ms)14992026/10/01 07:39:03 goose: successfully migrated database to version: 2026092312000015002026/10/01 07:39:03 OK 1_commit_pending_closure.sql (821.42µs)15012026/10/01 07:39:03 OK 2_object_stats_trigger.sql (200.75µs)15022026/10/01 07:39:03 OK 3_commit_push.sql (171.71µs)15032026/10/01 07:39:03 goose: up to current file version: 315042026/10/01 07:39:03 OK 20241026095416_initial_model.sql (264.04ms)15052026/10/01 07:39:03 OK 20251210153512_drop_unused_gin_index.sql (21.79ms)15062026/10/01 07:39:03 OK 20251218171726_add_pins.sql (48.16ms)15072026/10/01 07:39:03 OK 20260628120000_add_object_size_and_stats.sql (67.32ms)15082026/10/01 07:39:03 INFO Received uploads request method=POST path=/api/pending_closures15092026-10-01 07:39:03.965 UTC [69020] ERROR: relation "goose_db_version" does not exist at character 3615102026-10-01 07:39:03.965 UTC [69020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1511--- PASS: TestTombstonedObjectOfferedWithoutWaiting (5.86s)1512=== CONT TestClientPushesUseOnePush15132026/10/01 07:39:04 OK 20260905000000_add_claims.sql (129.27ms)15142026/10/01 07:39:04 OK 20260920000000_drop_claims.sql (103.23ms)15152026/10/01 07:39:04 OK 20260923120000_add_pushes.sql (35.27ms)15162026/10/01 07:39:04 goose: successfully migrated database to version: 2026092312000015172026/10/01 07:39:04 OK 1_commit_pending_closure.sql (1.25ms)15182026/10/01 07:39:04 OK 2_object_stats_trigger.sql (245.08µs)15192026/10/01 07:39:04 OK 3_commit_push.sql (217.04µs)15202026/10/01 07:39:04 goose: up to current file version: 315212026/10/01 07:39:04 OK 20241026095416_initial_model.sql (441.88ms)15222026/10/01 07:39:04 OK 20251210153512_drop_unused_gin_index.sql (26.22ms)15232026/10/01 07:39:04 INFO Aborted multipart uploads count=015242026/10/01 07:39:04 WARN Force mode enabled - objects will be deleted immediately without grace period15252026/10/01 07:39:04 OK 20251218171726_add_pins.sql (71.92ms)15262026/10/01 07:39:04 OK 20260628120000_add_object_size_and_stats.sql (100.18ms)15272026/10/01 07:39:04 INFO Received uploads request method=POST path=/api/pending_closures1528=== NAME TestOrphanedObjectsGCStressTest1529 orphaned_objects_gc_test.go:509: Stress test completed successfully:1530 orphaned_objects_gc_test.go:510: - Active objects preserved: 201531 orphaned_objects_gc_test.go:511: - Objects deleted: 2101532 orphaned_objects_gc_test.go:512: - Total GC'd: 2101533--- PASS: TestOrphanedObjectsGCStressTest (22.90s)1534=== CONT TestMetricsInventory15352026/10/01 07:39:04 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=015362026/10/01 07:39:04 INFO Vacuumed table table=pending_closures15372026/10/01 07:39:04 INFO Vacuumed table table=pending_objects15382026/10/01 07:39:04 INFO Vacuumed table table=multipart_uploads15392026/10/01 07:39:04 INFO Vacuumed table table=closures15402026/10/01 07:39:04 INFO Aborted multipart uploads count=015412026/10/01 07:39:04 WARN Force mode enabled - objects will be deleted immediately without grace period15422026/10/01 07:39:04 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=015432026/10/01 07:39:04 OK 20260905000000_add_claims.sql (150.79ms)15442026/10/01 07:39:04 INFO Vacuumed table table=objects1545--- PASS: TestGCSweepDeliversEachKeyOnce (6.95s)1546=== CONT TestService_NativeMTLS15472026/10/01 07:39:04 INFO Vacuumed table table=pending_closures15482026/10/01 07:39:05 OK 20260920000000_drop_claims.sql (103.94ms)15492026/10/01 07:39:05 INFO Vacuumed table table=pending_objects15502026/10/01 07:39:05 INFO Vacuumed table table=multipart_uploads15512026/10/01 07:39:05 INFO Vacuumed table table=closures15522026/10/01 07:39:05 OK 20260923120000_add_pushes.sql (5.01ms)15532026/10/01 07:39:05 goose: successfully migrated database to version: 2026092312000015542026/10/01 07:39:05 OK 1_commit_pending_closure.sql (1.26ms)15552026/10/01 07:39:05 OK 2_object_stats_trigger.sql (339.08µs)15562026/10/01 07:39:05 OK 3_commit_push.sql (272.25µs)15572026/10/01 07:39:05 goose: up to current file version: 315582026/10/01 07:39:05 INFO Vacuumed table table=objects1559--- PASS: TestGCSweepSkipsPendingObjects (6.24s)1560=== CONT TestGCBugBareHashReferences15612026/10/01 07:39:05 INFO Received uploads request method=POST path=/api/pending_closures15622026-10-01 07:39:05.558 UTC [69110] ERROR: relation "goose_db_version" does not exist at character 3615632026-10-01 07:39:05.558 UTC [69110] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15642026/10/01 07:39:05 INFO Aborted multipart uploads count=015652026/10/01 07:39:05 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=015662026/10/01 07:39:05 INFO Vacuumed table table=pending_closures15672026/10/01 07:39:05 INFO Vacuumed table table=pending_objects15682026/10/01 07:39:05 INFO Vacuumed table table=multipart_uploads15692026/10/01 07:39:05 INFO Vacuumed table table=closures15702026/10/01 07:39:05 INFO Vacuumed table table=objects15712026/10/01 07:39:05 INFO Aborted multipart uploads count=015722026/10/01 07:39:05 WARN Force mode enabled - objects will be deleted immediately without grace period15732026/10/01 07:39:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015742026/10/01 07:39:05 INFO Vacuumed table table=pending_closures15752026/10/01 07:39:05 INFO Vacuumed table table=pending_objects15762026/10/01 07:39:05 INFO Vacuumed table table=multipart_uploads15772026/10/01 07:39:05 INFO Vacuumed table table=closures15782026/10/01 07:39:05 INFO Vacuumed table table=objects1579--- PASS: TestPushDedupSurvivesConcurrentGC (6.17s)1580=== CONT TestClientMultipleUploads15812026/10/01 07:39:06 OK 20241026095416_initial_model.sql (328.66ms)15822026/10/01 07:39:06 OK 20251210153512_drop_unused_gin_index.sql (29.48ms)15832026/10/01 07:39:06 OK 20251218171726_add_pins.sql (22.02ms)15842026/10/01 07:39:06 OK 20260628120000_add_object_size_and_stats.sql (17.9ms)15852026-10-01 07:39:06.082 UTC [69125] ERROR: relation "goose_db_version" does not exist at character 3615862026-10-01 07:39:06.082 UTC [69125] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15872026-10-01 07:39:06.085 UTC [69126] ERROR: relation "goose_db_version" does not exist at character 3615882026-10-01 07:39:06.085 UTC [69126] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15892026/10/01 07:39:06 OK 20260905000000_add_claims.sql (39.57ms)15902026/10/01 07:39:06 OK 20260920000000_drop_claims.sql (58.4ms)15912026/10/01 07:39:06 OK 20260923120000_add_pushes.sql (26.14ms)15922026/10/01 07:39:06 goose: successfully migrated database to version: 2026092312000015932026/10/01 07:39:06 OK 1_commit_pending_closure.sql (5.25ms)15942026/10/01 07:39:06 OK 2_object_stats_trigger.sql (687.83µs)15952026/10/01 07:39:06 OK 3_commit_push.sql (402.75µs)15962026/10/01 07:39:06 goose: up to current file version: 315972026-10-01 07:39:06.454 UTC [69129] ERROR: relation "goose_db_version" does not exist at character 3615982026-10-01 07:39:06.454 UTC [69129] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15992026-10-01 07:39:06.489 UTC [69130] ERROR: relation "goose_db_version" does not exist at character 3616002026-10-01 07:39:06.489 UTC [69130] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16012026/10/01 07:39:06 OK 20241026095416_initial_model.sql (407.5ms)16022026/10/01 07:39:06 OK 20241026095416_initial_model.sql (406.58ms)16032026/10/01 07:39:06 INFO lead: acquired remote=192.0.2.1:123416042026/10/01 07:39:06 OK 20251210153512_drop_unused_gin_index.sql (15.67ms)16052026/10/01 07:39:06 OK 20251210153512_drop_unused_gin_index.sql (15.78ms)16062026/10/01 07:39:06 OK 20251218171726_add_pins.sql (57.47ms)16072026/10/01 07:39:06 OK 20251218171726_add_pins.sql (57.54ms)16082026/10/01 07:39:06 OK 20260628120000_add_object_size_and_stats.sql (53.98ms)16092026/10/01 07:39:06 OK 20260628120000_add_object_size_and_stats.sql (55.18ms)16102026/10/01 07:39:06 INFO lead: released remote=192.0.2.1:123416112026/10/01 07:39:06 OK 20260905000000_add_claims.sql (31.66ms)16122026/10/01 07:39:06 OK 20241026095416_initial_model.sql (173.48ms)16132026/10/01 07:39:06 OK 20241026095416_initial_model.sql (187.74ms)16142026/10/01 07:39:06 OK 20251210153512_drop_unused_gin_index.sql (13.36ms)16152026/10/01 07:39:06 OK 20260920000000_drop_claims.sql (31.27ms)16162026/10/01 07:39:06 OK 20260905000000_add_claims.sql (67.87ms)16172026/10/01 07:39:06 OK 20251210153512_drop_unused_gin_index.sql (10.51ms)16182026/10/01 07:39:06 OK 20260923120000_add_pushes.sql (9.3ms)16192026/10/01 07:39:06 goose: successfully migrated database to version: 2026092312000016202026/10/01 07:39:06 INFO lead: acquired remote=192.0.2.1:123416212026/10/01 07:39:06 OK 20251218171726_add_pins.sql (16.74ms)16222026/10/01 07:39:06 OK 1_commit_pending_closure.sql (11.02ms)16232026/10/01 07:39:06 OK 20251218171726_add_pins.sql (11.24ms)16242026/10/01 07:39:06 OK 20260920000000_drop_claims.sql (14.9ms)16252026/10/01 07:39:06 OK 2_object_stats_trigger.sql (1.15ms)16262026/10/01 07:39:06 OK 3_commit_push.sql (438.71µs)16272026/10/01 07:39:06 goose: up to current file version: 316282026/10/01 07:39:06 INFO lead: released remote=192.0.2.1:12341629--- PASS: TestLeadElectsOneAndHandsOver (5.80s)1630=== CONT TestPinProtectsFromGC16312026/10/01 07:39:06 OK 20260628120000_add_object_size_and_stats.sql (17.63ms)16322026/10/01 07:39:06 OK 20260923120000_add_pushes.sql (20.38ms)16332026/10/01 07:39:06 goose: successfully migrated database to version: 2026092312000016342026/10/01 07:39:06 OK 1_commit_pending_closure.sql (1.79ms)16352026/10/01 07:39:06 OK 2_object_stats_trigger.sql (283.42µs)16362026/10/01 07:39:06 OK 3_commit_push.sql (274.13µs)16372026/10/01 07:39:06 goose: up to current file version: 316382026/10/01 07:39:06 OK 20260628120000_add_object_size_and_stats.sql (52.08ms)16392026/10/01 07:39:06 OK 20260905000000_add_claims.sql (113.45ms)16402026/10/01 07:39:06 OK 20260920000000_drop_claims.sql (19.46ms)16412026/10/01 07:39:06 OK 20260905000000_add_claims.sql (108.29ms)16422026/10/01 07:39:06 OK 20260923120000_add_pushes.sql (22.76ms)16432026/10/01 07:39:06 goose: successfully migrated database to version: 2026092312000016442026/10/01 07:39:06 OK 1_commit_pending_closure.sql (4ms)16452026/10/01 07:39:06 OK 2_object_stats_trigger.sql (662.21µs)16462026/10/01 07:39:06 OK 3_commit_push.sql (465.17µs)16472026/10/01 07:39:06 goose: up to current file version: 316482026/10/01 07:39:07 OK 20260920000000_drop_claims.sql (25.27ms)16492026/10/01 07:39:07 OK 20260923120000_add_pushes.sql (32.41ms)16502026/10/01 07:39:07 goose: successfully migrated database to version: 2026092312000016512026/10/01 07:39:07 OK 1_commit_pending_closure.sql (2.04ms)16522026/10/01 07:39:07 OK 2_object_stats_trigger.sql (443.67µs)16532026/10/01 07:39:07 OK 3_commit_push.sql (346.21µs)16542026/10/01 07:39:07 goose: up to current file version: 316552026/10/01 07:39:07 INFO Received uploads request method=POST path=/api/pending_closures16562026/10/01 07:39:07 INFO Aborted multipart uploads count=016572026/10/01 07:39:07 WARN Force mode enabled - objects will be deleted immediately without grace period16582026/10/01 07:39:07 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016592026/10/01 07:39:07 INFO Vacuumed table table=pending_closures16602026/10/01 07:39:07 INFO Vacuumed table table=pending_objects16612026/10/01 07:39:07 INFO Vacuumed table table=multipart_uploads16622026/10/01 07:39:07 INFO Vacuumed table table=closures16632026/10/01 07:39:07 INFO Vacuumed table table=objects1664--- PASS: TestGCMetrics (5.54s)1665=== CONT TestClientSharedPathCommittedMidPush16662026/10/01 07:39:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16672026/10/01 07:39:07 INFO lead: acquired remote=192.0.2.1:123416682026/10/01 07:39:07 INFO lead: released remote=192.0.2.1:12341669--- PASS: TestLeadEndsOnShutdown (5.45s)1670=== CONT TestClientWithDependencies16712026-10-01 07:39:08.404 UTC [69144] ERROR: relation "goose_db_version" does not exist at character 3616722026-10-01 07:39:08.404 UTC [69144] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026-10-01 07:39:08.588 UTC [69150] ERROR: relation "goose_db_version" does not exist at character 3616742026-10-01 07:39:08.588 UTC [69150] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16752026-10-01 07:39:08.595 UTC [69151] ERROR: relation "goose_db_version" does not exist at character 3616762026-10-01 07:39:08.595 UTC [69151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026-10-01 07:39:08.597 UTC [69153] ERROR: relation "goose_db_version" does not exist at character 3616782026-10-01 07:39:08.597 UTC [69153] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16792026/10/01 07:39:08 OK 20241026095416_initial_model.sql (67.99ms)16802026/10/01 07:39:08 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)16812026/10/01 07:39:08 OK 20251218171726_add_pins.sql (1.86ms)16822026-10-01 07:39:08.607 UTC [69154] ERROR: relation "goose_db_version" does not exist at character 3616832026-10-01 07:39:08.607 UTC [69154] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16842026/10/01 07:39:08 OK 20260628120000_add_object_size_and_stats.sql (20.82ms)16852026/10/01 07:39:08 OK 20260905000000_add_claims.sql (31.47ms)16862026/10/01 07:39:08 OK 20260920000000_drop_claims.sql (11.25ms)16872026/10/01 07:39:08 OK 20260923120000_add_pushes.sql (3.3ms)16882026/10/01 07:39:08 goose: successfully migrated database to version: 2026092312000016892026/10/01 07:39:08 OK 1_commit_pending_closure.sql (1.38ms)16902026/10/01 07:39:08 OK 2_object_stats_trigger.sql (236.33µs)16912026/10/01 07:39:08 OK 3_commit_push.sql (242µs)16922026/10/01 07:39:08 goose: up to current file version: 316932026/10/01 07:39:08 OK 20241026095416_initial_model.sql (95.62ms)16942026/10/01 07:39:08 OK 20251210153512_drop_unused_gin_index.sql (9.4ms)16952026/10/01 07:39:08 OK 20241026095416_initial_model.sql (114.09ms)16962026/10/01 07:39:08 OK 20241026095416_initial_model.sql (140.83ms)16972026/10/01 07:39:08 OK 20251210153512_drop_unused_gin_index.sql (14.11ms)16982026/10/01 07:39:08 OK 20251210153512_drop_unused_gin_index.sql (19.38ms)16992026/10/01 07:39:08 OK 20251218171726_add_pins.sql (45.16ms)17002026/10/01 07:39:08 OK 20251218171726_add_pins.sql (53.17ms)17012026/10/01 07:39:08 OK 20251218171726_add_pins.sql (46.23ms)17022026/10/01 07:39:08 OK 20260628120000_add_object_size_and_stats.sql (52.75ms)17032026/10/01 07:39:08 OK 20241026095416_initial_model.sql (191.83ms)17042026/10/01 07:39:08 OK 20260628120000_add_object_size_and_stats.sql (52.61ms)17052026/10/01 07:39:08 OK 20251210153512_drop_unused_gin_index.sql (19.93ms)17062026/10/01 07:39:08 OK 20260628120000_add_object_size_and_stats.sql (52.8ms)17072026/10/01 07:39:08 OK 20251218171726_add_pins.sql (49.9ms)17082026/10/01 07:39:08 OK 20260905000000_add_claims.sql (126.69ms)17092026/10/01 07:39:08 OK 20260905000000_add_claims.sql (120.36ms)17102026/10/01 07:39:09 OK 20260628120000_add_object_size_and_stats.sql (83.47ms)17112026/10/01 07:39:09 OK 20260905000000_add_claims.sql (123.45ms)1712=== NAME TestClientCADerivations1713 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-67309-3657216313/TestClientCADerivations3224938962/001/store/k7awr63xk1izv00c60pna6cw99ahlm0w-ca-test17142026/10/01 07:39:09 OK 20260920000000_drop_claims.sql (100.19ms)17152026/10/01 07:39:09 OK 20260920000000_drop_claims.sql (84.68ms)17162026/10/01 07:39:09 OK 20260923120000_add_pushes.sql (24.96ms)17172026/10/01 07:39:09 goose: successfully migrated database to version: 2026092312000017182026/10/01 07:39:09 OK 1_commit_pending_closure.sql (1ms)17192026/10/01 07:39:09 OK 2_object_stats_trigger.sql (266.46µs)17202026/10/01 07:39:09 OK 3_commit_push.sql (223.38µs)17212026/10/01 07:39:09 goose: up to current file version: 317222026/10/01 07:39:09 OK 20260923120000_add_pushes.sql (42.27ms)17232026/10/01 07:39:09 goose: successfully migrated database to version: 2026092312000017242026/10/01 07:39:09 OK 20260920000000_drop_claims.sql (99.78ms)17252026/10/01 07:39:09 OK 1_commit_pending_closure.sql (974.83µs)17262026/10/01 07:39:09 OK 2_object_stats_trigger.sql (209.25µs)17272026/10/01 07:39:09 OK 3_commit_push.sql (198.88µs)17282026/10/01 07:39:09 goose: up to current file version: 317292026/10/01 07:39:09 OK 20260905000000_add_claims.sql (112.06ms)17302026/10/01 07:39:09 OK 20260923120000_add_pushes.sql (21.56ms)17312026/10/01 07:39:09 goose: successfully migrated database to version: 2026092312000017322026/10/01 07:39:09 OK 1_commit_pending_closure.sql (864.08µs)17332026/10/01 07:39:09 OK 2_object_stats_trigger.sql (204.38µs)17342026/10/01 07:39:09 OK 3_commit_push.sql (199.54µs)17352026/10/01 07:39:09 goose: up to current file version: 31736 client_ca_test.go:139: Found 1 dependencies (including self)17372026/10/01 07:39:09 OK 20260920000000_drop_claims.sql (55.85ms)17382026/10/01 07:39:09 OK 20260923120000_add_pushes.sql (20.64ms)17392026/10/01 07:39:09 goose: successfully migrated database to version: 2026092312000017402026/10/01 07:39:09 OK 1_commit_pending_closure.sql (911.25µs)17412026/10/01 07:39:09 OK 2_object_stats_trigger.sql (247.42µs)17422026/10/01 07:39:09 OK 3_commit_push.sql (224.71µs)17432026/10/01 07:39:09 goose: up to current file version: 317442026/10/01 07:39:09 INFO Received push request method=POST path=/api/pushes17452026/10/01 07:39:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17462026/10/01 07:39:09 INFO Uploading k7awr63xk1izv00c60pna6cw99ahlm0w-ca-test (144B)17472026/10/01 07:39:09 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17482026/10/01 07:39:09 WARN Failed to register uploaded object key=k7awr63xk1izv00c60pna6cw99ahlm0w.ls error="server returned 404: 404 page not found\n"17492026/10/01 07:39:09 WARN Failed to register uploaded object key=log/gpkkcjfh16lznqyrf7qd6i3h5a95giya-ca-test.drv error="server returned 404: 404 page not found\n"17502026/10/01 07:39:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17512026/10/01 07:39:09 INFO Signed narinfos id=1 count=117522026/10/01 07:39:09 INFO Uploading 1 narinfos17532026/10/01 07:39:09 INFO Received complete push request method=POST path=/api/pushes/1/complete17542026/10/01 07:39:09 WARN Failed to register uploaded object key=k7awr63xk1izv00c60pna6cw99ahlm0w.narinfo error="server returned 404: 404 page not found\n"17552026/10/01 07:39:09 INFO Upload complete. (249ms)1756 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientCADerivations3224938962/001/store/k7awr63xk1izv00c60pna6cw99ahlm0w-ca-test1757 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1758 Compression: zstd1759 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1760 NarSize: 1441761 References: 1762 Deriver: /nix/var/nix/builds/nix-67309-3657216313/TestClientCADerivations3224938962/001/store/gpkkcjfh16lznqyrf7qd6i3h5a95giya-ca-test.drv1763 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1764 client_ca_test.go:185: Checking for realisation files in S3...1765 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1766 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1767 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket42?endpoint=http://localhost:57287®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-67309-3657216313/TestClientCADerivations3224938962/001/store'1768 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11769--- PASS: TestGCBugBareHashReferences (4.56s)1770=== CONT TestRedundantMultipartUpload1771--- PASS: TestClientCADerivations (7.08s)1772=== CONT TestClientIntegration1773--- PASS: TestMetricsInventory (4.84s)1774=== CONT TestParseSize1775--- PASS: TestParseSize (0.00s)1776=== CONT TestClientErrorHandling1777=== RUN TestClientErrorHandling/InvalidStorePath1778=== PAUSE TestClientErrorHandling/InvalidStorePath1779=== RUN TestClientErrorHandling/InvalidAuthToken1780=== PAUSE TestClientErrorHandling/InvalidAuthToken1781=== RUN TestClientErrorHandling/ServerNotAvailable1782=== PAUSE TestClientErrorHandling/ServerNotAvailable1783=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit17842026/10/01 07:39:09 INFO Received push request method=POST path=/api/pushes17852026/10/01 07:39:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17862026/10/01 07:39:09 INFO Uploading pkmgdnn85dkvvz2qridxdi79930xva6d-b (248B)17872026/10/01 07:39:09 INFO Uploading 4qpwg30vn3clprb4l31301rn9bfldwls-shared-dep (136B)17882026/10/01 07:39:09 WARN Failed to register uploaded object key=4qpwg30vn3clprb4l31301rn9bfldwls.ls error="server returned 404: 404 page not found\n"17892026/10/01 07:39:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17902026/10/01 07:39:09 WARN Failed to register uploaded object key=nar/0ks5h6yc52fl8s44i4br3j60n526q8yy4v7ik2mm2r0cvjn2lc49.nar.zst error="server returned 404: 404 page not found\n"17912026/10/01 07:39:09 WARN Failed to register uploaded object key=pkmgdnn85dkvvz2qridxdi79930xva6d.ls error="server returned 404: 404 page not found\n"17922026/10/01 07:39:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17932026/10/01 07:39:09 WARN Failed to register uploaded object key=l5amdki3pn7brw2z0in7ibqyrrlrclhm.ls error="server returned 404: 404 page not found\n"17942026/10/01 07:39:09 INFO Signed narinfos id=1 count=317952026/10/01 07:39:09 INFO Uploading 3 narinfos17962026/10/01 07:39:09 WARN Failed to register uploaded object key=l5amdki3pn7brw2z0in7ibqyrrlrclhm.narinfo error="server returned 404: 404 page not found\n"17972026/10/01 07:39:09 WARN Failed to register uploaded object key=4qpwg30vn3clprb4l31301rn9bfldwls.narinfo error="server returned 404: 404 page not found\n"17982026/10/01 07:39:09 INFO Received complete push request method=POST path=/api/pushes/1/complete17992026/10/01 07:39:09 WARN Failed to register uploaded object key=pkmgdnn85dkvvz2qridxdi79930xva6d.narinfo error="server returned 404: 404 page not found\n"18002026/10/01 07:39:09 INFO Upload complete. (200ms)1801=== NAME TestClientPushesUseOnePush1802 client_pushes_test.go:97: Retrieved narinfo from S3:1803 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientPushesUseOnePush1794051781/001/store/4qpwg30vn3clprb4l31301rn9bfldwls-shared-dep1804 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1805 Compression: zstd1806 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821807 NarSize: 1361808 References: 1809 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1810 client_pushes_test.go:97: Retrieved narinfo from S3:1811 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientPushesUseOnePush1794051781/001/store/l5amdki3pn7brw2z0in7ibqyrrlrclhm-a1812 URL: nar/0ks5h6yc52fl8s44i4br3j60n526q8yy4v7ik2mm2r0cvjn2lc49.nar.zst1813 Compression: zstd1814 NarHash: sha256:0ks5h6yc52fl8s44i4br3j60n526q8yy4v7ik2mm2r0cvjn2lc491815 NarSize: 2481816 References: /nix/var/nix/builds/nix-67309-3657216313/TestClientPushesUseOnePush1794051781/001/store/4qpwg30vn3clprb4l31301rn9bfldwls-shared-dep1817 CA: text:sha256:0s9ppkzxf5mjdqhclyy82gyg51bj6pjlvg2nvmnlqm62ky42731s1818 client_pushes_test.go:97: Retrieved narinfo from S3:1819 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientPushesUseOnePush1794051781/001/store/pkmgdnn85dkvvz2qridxdi79930xva6d-b1820 URL: nar/0ks5h6yc52fl8s44i4br3j60n526q8yy4v7ik2mm2r0cvjn2lc49.nar.zst1821 Compression: zstd1822 NarHash: sha256:0ks5h6yc52fl8s44i4br3j60n526q8yy4v7ik2mm2r0cvjn2lc491823 NarSize: 2481824 References: /nix/var/nix/builds/nix-67309-3657216313/TestClientPushesUseOnePush1794051781/001/store/4qpwg30vn3clprb4l31301rn9bfldwls-shared-dep1825 CA: text:sha256:0s9ppkzxf5mjdqhclyy82gyg51bj6pjlvg2nvmnlqm62ky42731s1826--- PASS: TestClientPushesUseOnePush (5.94s)1827=== CONT TestPush_RejectsBadRequests18282026-10-01 07:39:09.929 UTC [69192] ERROR: relation "goose_db_version" does not exist at character 3618292026-10-01 07:39:09.929 UTC [69192] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18302026/10/01 07:39:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18312026/10/01 07:39:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1832--- PASS: TestService_NativeMTLS (5.04s)1833=== CONT TestCompletedNarNotReofferedAcrossClosures18342026/10/01 07:39:10 OK 20241026095416_initial_model.sql (96.93ms)18352026/10/01 07:39:10 OK 20251210153512_drop_unused_gin_index.sql (7.12ms)18362026/10/01 07:39:10 OK 20251218171726_add_pins.sql (32.95ms)18372026-10-01 07:39:10.170 UTC [69197] ERROR: relation "goose_db_version" does not exist at character 3618382026-10-01 07:39:10.170 UTC [69197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18392026/10/01 07:39:10 OK 20260628120000_add_object_size_and_stats.sql (40.86ms)18402026-10-01 07:39:10.220 UTC [69198] ERROR: relation "goose_db_version" does not exist at character 3618412026-10-01 07:39:10.220 UTC [69198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18422026/10/01 07:39:10 OK 20260905000000_add_claims.sql (50.2ms)18432026/10/01 07:39:10 OK 20260920000000_drop_claims.sql (17.51ms)18442026/10/01 07:39:10 OK 20260923120000_add_pushes.sql (10.68ms)18452026/10/01 07:39:10 goose: successfully migrated database to version: 2026092312000018462026/10/01 07:39:10 OK 1_commit_pending_closure.sql (3.56ms)18472026/10/01 07:39:10 OK 2_object_stats_trigger.sql (572.04µs)18482026/10/01 07:39:10 OK 3_commit_push.sql (370.25µs)18492026/10/01 07:39:10 goose: up to current file version: 318502026/10/01 07:39:10 OK 20241026095416_initial_model.sql (108.82ms)18512026/10/01 07:39:10 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)18522026/10/01 07:39:10 OK 20251218171726_add_pins.sql (21.14ms)18532026/10/01 07:39:10 OK 20241026095416_initial_model.sql (102.3ms)18542026/10/01 07:39:10 OK 20251210153512_drop_unused_gin_index.sql (10.05ms)18552026/10/01 07:39:10 OK 20260628120000_add_object_size_and_stats.sql (26.41ms)18562026/10/01 07:39:10 OK 20251218171726_add_pins.sql (21.52ms)1857=== NAME TestClientMultipleUploads1858 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-67309-3657216313/TestClientMultipleUploads171415561/001/store/vrfsi9lfns0d9w7mv374lsz830czd963-test-file-0.txt18592026/10/01 07:39:10 OK 20260905000000_add_claims.sql (22.19ms)18602026/10/01 07:39:10 OK 20260628120000_add_object_size_and_stats.sql (22.89ms)18612026/10/01 07:39:10 OK 20260920000000_drop_claims.sql (14.82ms)18622026/10/01 07:39:10 OK 20260923120000_add_pushes.sql (12.43ms)18632026/10/01 07:39:10 goose: successfully migrated database to version: 2026092312000018642026/10/01 07:39:10 OK 1_commit_pending_closure.sql (991.17µs)18652026/10/01 07:39:10 OK 2_object_stats_trigger.sql (249.25µs)18662026/10/01 07:39:10 OK 3_commit_push.sql (179.92µs)18672026/10/01 07:39:10 goose: up to current file version: 318682026/10/01 07:39:10 OK 20260905000000_add_claims.sql (43.61ms)18692026/10/01 07:39:10 OK 20260920000000_drop_claims.sql (19.17ms)1870 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-67309-3657216313/TestClientMultipleUploads171415561/001/store/vy5l5bbyh3ilbvr9vfvlkly5fbkffbny-test-file-1.txt18712026/10/01 07:39:10 OK 20260923120000_add_pushes.sql (21.7ms)18722026/10/01 07:39:10 goose: successfully migrated database to version: 2026092312000018732026/10/01 07:39:10 OK 1_commit_pending_closure.sql (910.54µs)18742026/10/01 07:39:10 OK 2_object_stats_trigger.sql (237.04µs)18752026/10/01 07:39:10 OK 3_commit_push.sql (199.92µs)18762026/10/01 07:39:10 goose: up to current file version: 31877 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-67309-3657216313/TestClientMultipleUploads171415561/001/store/5kwjivci8ps2hh9s56kg82a6qmg24qdc-test-file-2.txt18782026/10/01 07:39:10 INFO Received push request method=POST path=/api/pushes18792026/10/01 07:39:10 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18802026/10/01 07:39:10 INFO Uploading vy5l5bbyh3ilbvr9vfvlkly5fbkffbny-test-file-1.txt (160B)18812026/10/01 07:39:10 INFO Uploading 5kwjivci8ps2hh9s56kg82a6qmg24qdc-test-file-2.txt (160B)18822026/10/01 07:39:10 INFO Uploading vrfsi9lfns0d9w7mv374lsz830czd963-test-file-0.txt (160B)18832026/10/01 07:39:10 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18842026/10/01 07:39:10 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18852026/10/01 07:39:10 WARN Failed to register uploaded object key=vrfsi9lfns0d9w7mv374lsz830czd963.ls error="server returned 404: 404 page not found\n"18862026/10/01 07:39:10 WARN Failed to register uploaded object key=5kwjivci8ps2hh9s56kg82a6qmg24qdc.ls error="server returned 404: 404 page not found\n"18872026/10/01 07:39:10 WARN Failed to register uploaded object key=vy5l5bbyh3ilbvr9vfvlkly5fbkffbny.ls error="server returned 404: 404 page not found\n"18882026/10/01 07:39:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18892026/10/01 07:39:10 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18902026/10/01 07:39:10 INFO Signed narinfos id=1 count=318912026/10/01 07:39:10 INFO Uploading 3 narinfos18922026/10/01 07:39:10 INFO Received complete push request method=POST path=/api/pushes/1/complete18932026/10/01 07:39:10 WARN Failed to register uploaded object key=vy5l5bbyh3ilbvr9vfvlkly5fbkffbny.narinfo error="server returned 404: 404 page not found\n"18942026/10/01 07:39:10 WARN Failed to register uploaded object key=vrfsi9lfns0d9w7mv374lsz830czd963.narinfo error="server returned 404: 404 page not found\n"18952026/10/01 07:39:10 WARN Failed to register uploaded object key=5kwjivci8ps2hh9s56kg82a6qmg24qdc.narinfo error="server returned 404: 404 page not found\n"18962026/10/01 07:39:10 INFO Upload complete. (150ms)1897 client_integration_test.go:369: Uploaded 3 paths in 184.157042ms1898=== NAME TestPinProtectsFromGC1899 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-67309-3657216313/TestPinProtectsFromGC2486879371/001/store/4plwlzw32bd4mkcyxqka1nascwkgv2ax-pinned-file.txt1900 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-67309-3657216313/TestPinProtectsFromGC2486879371/001/store/l8sfk2kw2q2bwvq54bzshv9gdg805fiq-unpinned-file.txt1901--- PASS: TestClientMultipleUploads (4.93s)1902=== CONT TestPresignedUploadRegisteredBeforeCommit19032026/10/01 07:39:10 INFO Received push request method=POST path=/api/pushes19042026/10/01 07:39:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19052026/10/01 07:39:10 INFO Uploading 4plwlzw32bd4mkcyxqka1nascwkgv2ax-pinned-file.txt (128B)19062026/10/01 07:39:10 WARN Failed to register uploaded object key=4plwlzw32bd4mkcyxqka1nascwkgv2ax.ls error="server returned 404: 404 page not found\n"19072026/10/01 07:39:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19082026/10/01 07:39:10 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19092026/10/01 07:39:10 INFO Signed narinfos id=1 count=119102026/10/01 07:39:10 INFO Uploading 1 narinfos19112026/10/01 07:39:11 INFO Received complete push request method=POST path=/api/pushes/1/complete19122026/10/01 07:39:11 WARN Failed to register uploaded object key=4plwlzw32bd4mkcyxqka1nascwkgv2ax.narinfo error="server returned 404: 404 page not found\n"19132026/10/01 07:39:11 INFO Upload complete. (226ms)19142026/10/01 07:39:11 INFO Received push request method=POST path=/api/pushes19152026/10/01 07:39:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19162026/10/01 07:39:11 INFO Uploading l8sfk2kw2q2bwvq54bzshv9gdg805fiq-unpinned-file.txt (128B)19172026/10/01 07:39:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19182026/10/01 07:39:11 INFO Signed narinfos id=2 count=119192026/10/01 07:39:11 WARN Failed to register uploaded object key=l8sfk2kw2q2bwvq54bzshv9gdg805fiq.ls error="server returned 404: 404 page not found\n"19202026/10/01 07:39:11 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19212026/10/01 07:39:11 INFO Uploading 1 narinfos19222026/10/01 07:39:11 INFO Received complete push request method=POST path=/api/pushes/2/complete19232026/10/01 07:39:11 WARN Failed to register uploaded object key=l8sfk2kw2q2bwvq54bzshv9gdg805fiq.narinfo error="server returned 404: 404 page not found\n"19242026/10/01 07:39:11 INFO Upload complete. (111ms)19252026/10/01 07:39:11 INFO Received create pin request method=POST path=/api/pins/myapp19262026/10/01 07:39:11 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-67309-3657216313/TestPinProtectsFromGC2486879371/001/store/4plwlzw32bd4mkcyxqka1nascwkgv2ax-pinned-file.txt narinfo_key=4plwlzw32bd4mkcyxqka1nascwkgv2ax.narinfo19272026/10/01 07:39:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures19282026/10/01 07:39:11 INFO Garbage collection started19292026/10/01 07:39:11 INFO Aborted multipart uploads count=019302026/10/01 07:39:11 WARN Force mode enabled - objects will be deleted immediately without grace period19312026/10/01 07:39:11 INFO Received push request method=POST path=/api/pushes19322026/10/01 07:39:11 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=019332026/10/01 07:39:11 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19342026/10/01 07:39:11 INFO Uploading wpim9rqd1j8j90yx5ysscvz1knm6h61q-shared-dep (136B)19352026/10/01 07:39:11 INFO Uploading sff6qhh6lbvwj6n84rr8j2xi5lh3bpaj-top (256B)19362026/10/01 07:39:11 INFO Vacuumed table table=pending_closures19372026/10/01 07:39:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19382026/10/01 07:39:11 WARN Failed to register uploaded object key=sff6qhh6lbvwj6n84rr8j2xi5lh3bpaj.ls error="server returned 404: 404 page not found\n"19392026/10/01 07:39:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19402026/10/01 07:39:11 WARN Failed to register uploaded object key=wpim9rqd1j8j90yx5ysscvz1knm6h61q.ls error="server returned 404: 404 page not found\n"19412026/10/01 07:39:11 WARN Failed to register uploaded object key=nar/0aifm4m0dmz14rqc53p08m8vafzqy27b538xm1x375q139zilvdd.nar.zst error="server returned 404: 404 page not found\n"19422026/10/01 07:39:11 INFO Signed narinfos id=1 count=219432026/10/01 07:39:11 INFO Uploading 2 narinfos19442026/10/01 07:39:11 INFO Vacuumed table table=pending_objects19452026/10/01 07:39:11 WARN Failed to register uploaded object key=sff6qhh6lbvwj6n84rr8j2xi5lh3bpaj.narinfo error="server returned 404: 404 page not found\n"19462026/10/01 07:39:11 INFO Vacuumed table table=multipart_uploads19472026/10/01 07:39:11 INFO Received complete push request method=POST path=/api/pushes/1/complete19482026/10/01 07:39:11 WARN Failed to register uploaded object key=wpim9rqd1j8j90yx5ysscvz1knm6h61q.narinfo error="server returned 404: 404 page not found\n"19492026/10/01 07:39:11 INFO Vacuumed table table=closures19502026/10/01 07:39:11 INFO Upload complete. (184ms)1951=== NAME TestClientSharedPathCommittedMidPush1952 client_integration_test.go:680: Retrieved narinfo from S3:1953 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientSharedPathCommittedMidPush4057919046/001/store/wpim9rqd1j8j90yx5ysscvz1knm6h61q-shared-dep1954 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1955 Compression: zstd1956 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821957 NarSize: 1361958 References: 1959 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1960 client_integration_test.go:680: Retrieved narinfo from S3:1961 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientSharedPathCommittedMidPush4057919046/001/store/sff6qhh6lbvwj6n84rr8j2xi5lh3bpaj-top1962 URL: nar/0aifm4m0dmz14rqc53p08m8vafzqy27b538xm1x375q139zilvdd.nar.zst1963 Compression: zstd1964 NarHash: sha256:0aifm4m0dmz14rqc53p08m8vafzqy27b538xm1x375q139zilvdd1965 NarSize: 2561966 References: /nix/var/nix/builds/nix-67309-3657216313/TestClientSharedPathCommittedMidPush4057919046/001/store/wpim9rqd1j8j90yx5ysscvz1knm6h61q-shared-dep1967 CA: text:sha256:0am69pkkp0s34pdfjgf8ldabfq5igxng02f7jl0rvb2h26amj29919682026/10/01 07:39:11 INFO Vacuumed table table=objects1969--- PASS: TestClientSharedPathCommittedMidPush (3.95s)1970=== CONT TestService_Rustfstest19712026-10-01 07:39:11.563 UTC [69263] ERROR: relation "goose_db_version" does not exist at character 3619722026-10-01 07:39:11.563 UTC [69263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19732026-10-01 07:39:11.566 UTC [69264] ERROR: relation "goose_db_version" does not exist at character 3619742026-10-01 07:39:11.566 UTC [69264] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19752026-10-01 07:39:11.618 UTC [69265] ERROR: relation "goose_db_version" does not exist at character 3619762026-10-01 07:39:11.618 UTC [69265] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19772026-10-01 07:39:11.630 UTC [69267] ERROR: relation "goose_db_version" does not exist at character 3619782026-10-01 07:39:11.630 UTC [69267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1979=== NAME TestClientWithDependencies1980 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-67309-3657216313/TestClientWithDependencies491261751/001/store/8ns8agf1wnm7z4b3hnhscab830xcsgmq-test-script19812026-10-01 07:39:11.633 UTC [69266] ERROR: relation "goose_db_version" does not exist at character 3619822026-10-01 07:39:11.633 UTC [69266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1983 client_integration_test.go:615: Found 1 dependencies (including self)19842026/10/01 07:39:11 OK 20241026095416_initial_model.sql (82.61ms)19852026/10/01 07:39:11 OK 20241026095416_initial_model.sql (69.39ms)19862026/10/01 07:39:11 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)19872026/10/01 07:39:11 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)19882026/10/01 07:39:11 OK 20241026095416_initial_model.sql (42.98ms)19892026/10/01 07:39:11 OK 20251218171726_add_pins.sql (4.24ms)19902026/10/01 07:39:11 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)19912026/10/01 07:39:11 OK 20251218171726_add_pins.sql (4.95ms)19922026/10/01 07:39:11 OK 20251218171726_add_pins.sql (4.41ms)19932026/10/01 07:39:11 OK 20260628120000_add_object_size_and_stats.sql (6.31ms)19942026/10/01 07:39:11 OK 20241026095416_initial_model.sql (25.38ms)19952026/10/01 07:39:11 OK 20241026095416_initial_model.sql (29.86ms)19962026/10/01 07:39:11 OK 20260628120000_add_object_size_and_stats.sql (7.84ms)19972026/10/01 07:39:11 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)19982026/10/01 07:39:11 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)19992026/10/01 07:39:11 OK 20260628120000_add_object_size_and_stats.sql (7.23ms)20002026/10/01 07:39:11 OK 20260905000000_add_claims.sql (6.73ms)20012026/10/01 07:39:11 OK 20251218171726_add_pins.sql (4.91ms)20022026/10/01 07:39:11 OK 20251218171726_add_pins.sql (5ms)20032026/10/01 07:39:11 OK 20260905000000_add_claims.sql (6.72ms)20042026/10/01 07:39:11 OK 20260920000000_drop_claims.sql (2.35ms)20052026/10/01 07:39:11 OK 20260905000000_add_claims.sql (4.06ms)20062026/10/01 07:39:11 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)20072026/10/01 07:39:11 OK 20260920000000_drop_claims.sql (2.41ms)20082026/10/01 07:39:11 OK 20260923120000_add_pushes.sql (2.35ms)20092026/10/01 07:39:11 goose: successfully migrated database to version: 2026092312000020102026/10/01 07:39:11 OK 20260923120000_add_pushes.sql (2.6ms)20112026/10/01 07:39:11 goose: successfully migrated database to version: 2026092312000020122026/10/01 07:39:11 OK 20260920000000_drop_claims.sql (4.23ms)20132026/10/01 07:39:11 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)20142026/10/01 07:39:11 OK 1_commit_pending_closure.sql (3.12ms)20152026/10/01 07:39:11 OK 2_object_stats_trigger.sql (691.25µs)20162026/10/01 07:39:11 OK 20260923120000_add_pushes.sql (2.08ms)20172026/10/01 07:39:11 goose: successfully migrated database to version: 2026092312000020182026/10/01 07:39:11 OK 3_commit_push.sql (1.5ms)20192026/10/01 07:39:11 goose: up to current file version: 320202026/10/01 07:39:11 OK 1_commit_pending_closure.sql (3.05ms)20212026/10/01 07:39:11 OK 20260905000000_add_claims.sql (6.38ms)20222026/10/01 07:39:11 OK 2_object_stats_trigger.sql (752.04µs)20232026/10/01 07:39:11 OK 1_commit_pending_closure.sql (2.2ms)20242026/10/01 07:39:11 OK 3_commit_push.sql (537.08µs)20252026/10/01 07:39:11 goose: up to current file version: 320262026/10/01 07:39:11 OK 20260905000000_add_claims.sql (4.52ms)20272026/10/01 07:39:11 OK 2_object_stats_trigger.sql (718.54µs)20282026/10/01 07:39:11 OK 3_commit_push.sql (577.13µs)20292026/10/01 07:39:11 goose: up to current file version: 320302026/10/01 07:39:11 OK 20260920000000_drop_claims.sql (2.53ms)20312026/10/01 07:39:11 OK 20260920000000_drop_claims.sql (1.68ms)20322026/10/01 07:39:11 OK 20260923120000_add_pushes.sql (773.71µs)20332026/10/01 07:39:11 goose: successfully migrated database to version: 2026092312000020342026/10/01 07:39:11 OK 20260923120000_add_pushes.sql (699.04µs)20352026/10/01 07:39:11 goose: successfully migrated database to version: 2026092312000020362026/10/01 07:39:11 OK 1_commit_pending_closure.sql (1.71ms)20372026/10/01 07:39:11 OK 1_commit_pending_closure.sql (1.53ms)20382026/10/01 07:39:11 OK 2_object_stats_trigger.sql (275µs)20392026/10/01 07:39:11 OK 3_commit_push.sql (201.38µs)20402026/10/01 07:39:11 goose: up to current file version: 320412026/10/01 07:39:11 OK 2_object_stats_trigger.sql (256.67µs)20422026/10/01 07:39:11 OK 3_commit_push.sql (168.21µs)20432026/10/01 07:39:11 goose: up to current file version: 320442026/10/01 07:39:11 INFO Received push request method=POST path=/api/pushes20452026/10/01 07:39:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20462026/10/01 07:39:11 INFO Uploading 8ns8agf1wnm7z4b3hnhscab830xcsgmq-test-script (136B)20472026/10/01 07:39:11 WARN Failed to register uploaded object key=8ns8agf1wnm7z4b3hnhscab830xcsgmq.ls error="server returned 404: 404 page not found\n"20482026/10/01 07:39:11 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20492026/10/01 07:39:11 WARN Failed to register uploaded object key=log/7lw1san928w5qpqribigml1k64licrhk-test-script.drv error="server returned 404: 404 page not found\n"20502026/10/01 07:39:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20512026/10/01 07:39:11 INFO Signed narinfos id=1 count=120522026/10/01 07:39:11 INFO Uploading 1 narinfos20532026/10/01 07:39:11 INFO Received complete push request method=POST path=/api/pushes/1/complete20542026/10/01 07:39:11 WARN Failed to register uploaded object key=8ns8agf1wnm7z4b3hnhscab830xcsgmq.narinfo error="server returned 404: 404 page not found\n"20552026/10/01 07:39:11 INFO Upload complete. (198ms)2056 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-67309-3657216313/TestClientWithDependencies491261751/001/store) requires matching store prefix2057--- PASS: TestClientWithDependencies (4.15s)2058=== CONT TestCompleteMultipartUpload_ErrorButObjectExists2059=== NAME TestClientIntegration2060 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-67309-3657216313/TestClientIntegration3483428166/002/store/7d1wd6jg81zr6h20rgimwhs1cnvizawb-test-file.txt20612026/10/01 07:39:12 WARN Rate limiter enabled after throttle name=s3-test rate=520622026/10/01 07:39:12 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2063=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2064 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102065 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002066--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.52s)2067=== CONT TestPush_SignsNarinfosOfItsPendingObjects20682026/10/01 07:39:12 INFO Received uploads request method=POST path=/api/pending_closures20692026/10/01 07:39:12 INFO Received push request method=POST path=/api/pushes20702026/10/01 07:39:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20712026/10/01 07:39:12 INFO Uploading 7d1wd6jg81zr6h20rgimwhs1cnvizawb-test-file.txt (152B)20722026/10/01 07:39:12 WARN Failed to register uploaded object key=7d1wd6jg81zr6h20rgimwhs1cnvizawb.ls error="server returned 404: 404 page not found\n"20732026/10/01 07:39:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20742026/10/01 07:39:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20752026/10/01 07:39:12 INFO Signed narinfos id=1 count=120762026/10/01 07:39:12 INFO Uploading 1 narinfos20772026/10/01 07:39:12 INFO Received uploads request method=POST path=/api/pending_closures20782026/10/01 07:39:12 INFO Received complete push request method=POST path=/api/pushes/1/complete20792026/10/01 07:39:12 WARN Failed to register uploaded object key=7d1wd6jg81zr6h20rgimwhs1cnvizawb.narinfo error="server returned 404: 404 page not found\n"20802026/10/01 07:39:12 INFO Upload complete. (197ms)20812026/10/01 07:39:12 INFO All 1 paths already cached2082=== NAME TestClientIntegration2083 client_integration_test.go:312: Retrieved narinfo from S3:2084 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestClientIntegration3483428166/002/store/7d1wd6jg81zr6h20rgimwhs1cnvizawb-test-file.txt2085 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2086 Compression: zstd2087 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12088 NarSize: 1522089 References: 2090 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12091 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2092 client_integration_test.go:313: Decompressed .ls content (64 bytes):2093 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2094 client_integration_test.go:316: Testing garbage collection...20952026/10/01 07:39:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures20962026/10/01 07:39:12 INFO Garbage collection started20972026/10/01 07:39:12 INFO Aborted multipart uploads count=020982026/10/01 07:39:12 WARN Force mode enabled - objects will be deleted immediately without grace period20992026/10/01 07:39:12 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=021002026/10/01 07:39:12 INFO Received push request method=POST path=/api/pushes21012026/10/01 07:39:12 INFO Vacuumed table table=pending_closures21022026/10/01 07:39:12 INFO Vacuumed table table=pending_objects21032026/10/01 07:39:12 INFO Vacuumed table table=multipart_uploads21042026/10/01 07:39:12 INFO Received complete push request method=POST path=/api/pushes/1/complete21052026/10/01 07:39:12 INFO Vacuumed table table=closures21062026/10/01 07:39:12 INFO Received push request method=POST path=/api/pushes21072026/10/01 07:39:12 INFO Vacuumed table table=objects21082026/10/01 07:39:12 INFO Aborted multipart uploads count=021092026/10/01 07:39:12 WARN Force mode enabled - objects will be deleted immediately without grace period21102026/10/01 07:39:12 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=021112026/10/01 07:39:12 INFO Vacuumed table table=pending_closures2112=== RUN TestPush_RejectsBadRequests/no_roots2113=== PAUSE TestPush_RejectsBadRequests/no_roots2114=== RUN TestPush_RejectsBadRequests/no_objects2115=== PAUSE TestPush_RejectsBadRequests/no_objects2116=== RUN TestPush_RejectsBadRequests/bad_root2117=== PAUSE TestPush_RejectsBadRequests/bad_root2118=== RUN TestPush_RejectsBadRequests/root_not_in_objects2119=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2120=== CONT TestNARDeduplicationMetadataUploadBug21212026/10/01 07:39:13 INFO Vacuumed table table=pending_objects21222026/10/01 07:39:13 INFO Vacuumed table table=multipart_uploads21232026/10/01 07:39:13 INFO Vacuumed table table=closures21242026-10-01 07:39:13.137 UTC [69290] ERROR: relation "goose_db_version" does not exist at character 3621252026-10-01 07:39:13.137 UTC [69290] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21262026/10/01 07:39:13 INFO Vacuumed table table=objects21272026/10/01 07:39:13 INFO Received complete push request method=POST path=/api/pushes/2/complete2128--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.49s)2129=== CONT TestPush_OverlappingRootsStoreOneRowPerKey21302026/10/01 07:39:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02131=== NAME TestPinProtectsFromGC2132 client_integration_test.go:794: Pin successfully protected closure from garbage collection2133--- PASS: TestPinProtectsFromGC (6.59s)2134=== CONT TestPush_CompleteCommitsEveryRoot21352026/10/01 07:39:13 INFO Received uploads request method=POST path=/api/pending_closures21362026/10/01 07:39:13 OK 20241026095416_initial_model.sql (259.87ms)21372026/10/01 07:39:13 OK 20251210153512_drop_unused_gin_index.sql (16.22ms)21382026/10/01 07:39:13 OK 20251218171726_add_pins.sql (37.51ms)21392026/10/01 07:39:13 OK 20260628120000_add_object_size_and_stats.sql (63.47ms)21402026-10-01 07:39:13.699 UTC [69307] ERROR: relation "goose_db_version" does not exist at character 3621412026-10-01 07:39:13.699 UTC [69307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21422026/10/01 07:39:13 OK 20260905000000_add_claims.sql (80.58ms)21432026/10/01 07:39:13 OK 20260920000000_drop_claims.sql (22.13ms)21442026/10/01 07:39:13 OK 20260923120000_add_pushes.sql (9.95ms)21452026/10/01 07:39:13 goose: successfully migrated database to version: 2026092312000021462026/10/01 07:39:13 OK 1_commit_pending_closure.sql (1.54ms)21472026/10/01 07:39:13 OK 2_object_stats_trigger.sql (395.58µs)21482026/10/01 07:39:13 OK 3_commit_push.sql (274.58µs)21492026/10/01 07:39:13 goose: up to current file version: 321502026/10/01 07:39:14 OK 20241026095416_initial_model.sql (343.46ms)21512026/10/01 07:39:14 OK 20251210153512_drop_unused_gin_index.sql (33.57ms)21522026/10/01 07:39:14 OK 20251218171726_add_pins.sql (68.89ms)21532026/10/01 07:39:14 OK 20260628120000_add_object_size_and_stats.sql (50.52ms)21542026/10/01 07:39:14 INFO Received uploads request method=POST path=/api/pending_closures21552026/10/01 07:39:14 OK 20260905000000_add_claims.sql (116.89ms)21562026/10/01 07:39:14 OK 20260920000000_drop_claims.sql (21.19ms)21572026/10/01 07:39:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst21582026/10/01 07:39:14 INFO Received uploads request method=POST path=/api/pending_closures2159--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.56s)2160=== CONT TestService_RequireScope_OIDC21612026/10/01 07:39:14 OK 20260923120000_add_pushes.sql (23.08ms)21622026/10/01 07:39:14 goose: successfully migrated database to version: 2026092312000021632026/10/01 07:39:14 OK 1_commit_pending_closure.sql (1.24ms)21642026/10/01 07:39:14 OK 2_object_stats_trigger.sql (324.04µs)21652026/10/01 07:39:14 OK 3_commit_push.sql (280.83µs)21662026/10/01 07:39:14 goose: up to current file version: 321672026/10/01 07:39:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58041/oidc21682026/10/01 07:39:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02169=== NAME TestClientIntegration2170 client_integration_test.go:323: Objects in database after GC:2171 client_integration_test.go:323: Successfully deleted all objects with GC --force2172--- PASS: TestClientIntegration (5.05s)2173=== CONT TestCacheConfigHandler2174=== RUN TestCacheConfigHandler/full_config,_no_issuer2175=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2176=== RUN TestCacheConfigHandler/no_cache_url_configured2177=== PAUSE TestCacheConfigHandler/no_cache_url_configured2178=== RUN TestCacheConfigHandler/no_signing_keys2179=== PAUSE TestCacheConfigHandler/no_signing_keys2180=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2181=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2182=== CONT TestCacheStatsHandler21832026/10/01 07:39:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2184--- PASS: TestService_Rustfstest (3.32s)2185=== CONT TestService_AuthMiddleware_OIDC21862026/10/01 07:39:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTEzOTQxOWEtNzkzNC00YmRiLTk2YmYtOWZiMjY5ZTIzMjg5LmZmNDBiNjYyLTU5MTYtNGQxNi1iMmFkLTdlMDVlZGFiMzhkNHgxNzkwODQwMzUyMzY3Njk2MDAw parts=122187--- PASS: TestRedundantMultipartUpload (5.24s)2188=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21892026/10/01 07:39:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58051/oidc21902026-10-01 07:39:15.273 UTC [69320] ERROR: relation "goose_db_version" does not exist at character 3621912026-10-01 07:39:15.273 UTC [69320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21922026/10/01 07:39:15 OK 20241026095416_initial_model.sql (261.99ms)21932026/10/01 07:39:15 OK 20251210153512_drop_unused_gin_index.sql (16.86ms)21942026/10/01 07:39:15 OK 20251218171726_add_pins.sql (59.78ms)21952026/10/01 07:39:15 OK 20260628120000_add_object_size_and_stats.sql (69.52ms)21962026-10-01 07:39:15.922 UTC [69323] ERROR: relation "goose_db_version" does not exist at character 3621972026-10-01 07:39:15.922 UTC [69323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21982026/10/01 07:39:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21992026/10/01 07:39:16 OK 20260905000000_add_claims.sql (136.81ms)22002026/10/01 07:39:16 OK 20260920000000_drop_claims.sql (84.06ms)22012026/10/01 07:39:16 OK 20260923120000_add_pushes.sql (41.57ms)22022026/10/01 07:39:16 goose: successfully migrated database to version: 2026092312000022032026/10/01 07:39:16 OK 1_commit_pending_closure.sql (5.29ms)22042026/10/01 07:39:16 OK 2_object_stats_trigger.sql (1.04ms)22052026/10/01 07:39:16 OK 3_commit_push.sql (815.79µs)22062026/10/01 07:39:16 goose: up to current file version: 322072026/10/01 07:39:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTEzOTQxOWEtNzkzNC00YmRiLTk2YmYtOWZiMjY5ZTIzMjg5LmE4OGMwNDI5LTgyMTUtNDM1MS1hMDJiLWNhYmZkMzg0ZDUwNXgxNzkwODQwMzUzNTEwNzk1MDAw parts=1222082026/10/01 07:39:16 INFO Received uploads request method=POST path=/api/pending_closures2209--- PASS: TestCompletedNarNotReofferedAcrossClosures (6.26s)2210=== CONT TestService_ReadAuthMiddleware22112026/10/01 07:39:16 OK 20241026095416_initial_model.sql (367.23ms)22122026/10/01 07:39:16 OK 20251210153512_drop_unused_gin_index.sql (22.44ms)22132026/10/01 07:39:16 OK 20251218171726_add_pins.sql (61.65ms)22142026/10/01 07:39:16 OK 20260628120000_add_object_size_and_stats.sql (53.78ms)22152026/10/01 07:39:16 OK 20260905000000_add_claims.sql (135.15ms)22162026/10/01 07:39:16 INFO Received uploads request method=POST path=/api/pending_closures22172026/10/01 07:39:16 OK 20260920000000_drop_claims.sql (118.09ms)22182026/10/01 07:39:16 OK 20260923120000_add_pushes.sql (30.79ms)22192026/10/01 07:39:16 goose: successfully migrated database to version: 2026092312000022202026/10/01 07:39:16 OK 1_commit_pending_closure.sql (2.08ms)22212026/10/01 07:39:16 OK 2_object_stats_trigger.sql (486.46µs)22222026/10/01 07:39:16 OK 3_commit_push.sql (375.83µs)22232026/10/01 07:39:16 goose: up to current file version: 322242026/10/01 07:39:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22252026/10/01 07:39:17 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTEzOTQxOWEtNzkzNC00YmRiLTk2YmYtOWZiMjY5ZTIzMjg5LjM0NWVmNjdhLTZlYzctNDQ5MS05M2VmLTI4MjI2NWE4MDE0ZngxNzkwODQwMzU2Nzc2MjIwMDAw22262026/10/01 07:39:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTEzOTQxOWEtNzkzNC00YmRiLTk2YmYtOWZiMjY5ZTIzMjg5LjM0NWVmNjdhLTZlYzctNDQ5MS05M2VmLTI4MjI2NWE4MDE0ZngxNzkwODQwMzU2Nzc2MjIwMDAw parts=12227--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.22s)2228=== CONT TestService_ReadScope_PublicByDefault22292026/10/01 07:39:17 INFO Received push request method=POST path=/api/pushes22302026-10-01 07:39:17.395 UTC [69336] ERROR: relation "goose_db_version" does not exist at character 3622312026-10-01 07:39:17.395 UTC [69336] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22322026-10-01 07:39:17.397 UTC [69337] ERROR: relation "goose_db_version" does not exist at character 3622332026-10-01 07:39:17.397 UTC [69337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22342026/10/01 07:39:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22352026/10/01 07:39:17 INFO Signed narinfos id=1 count=12236--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (5.15s)2237=== CONT TestService_AuthMiddleware_MTLSProxyHeader22382026-10-01 07:39:17.741 UTC [69350] ERROR: relation "goose_db_version" does not exist at character 3622392026-10-01 07:39:17.741 UTC [69350] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22402026/10/01 07:39:17 OK 20241026095416_initial_model.sql (278.09ms)22412026/10/01 07:39:17 OK 20251210153512_drop_unused_gin_index.sql (19.93ms)22422026/10/01 07:39:17 OK 20241026095416_initial_model.sql (297.01ms)22432026/10/01 07:39:17 OK 20251210153512_drop_unused_gin_index.sql (9.44ms)22442026/10/01 07:39:17 OK 20251218171726_add_pins.sql (41.47ms)22452026/10/01 07:39:17 OK 20251218171726_add_pins.sql (50.52ms)22462026/10/01 07:39:17 OK 20260628120000_add_object_size_and_stats.sql (26.44ms)22472026/10/01 07:39:17 OK 20260628120000_add_object_size_and_stats.sql (32.45ms)22482026/10/01 07:39:17 OK 20260905000000_add_claims.sql (68.42ms)22492026/10/01 07:39:17 OK 20260905000000_add_claims.sql (69.6ms)22502026/10/01 07:39:17 OK 20241026095416_initial_model.sql (147.68ms)22512026/10/01 07:39:17 OK 20251210153512_drop_unused_gin_index.sql (18.7ms)22522026/10/01 07:39:17 OK 20260920000000_drop_claims.sql (65.41ms)22532026/10/01 07:39:18 OK 20260920000000_drop_claims.sql (59.44ms)22542026/10/01 07:39:18 OK 20260923120000_add_pushes.sql (21.18ms)22552026/10/01 07:39:18 goose: successfully migrated database to version: 2026092312000022562026/10/01 07:39:18 OK 20251218171726_add_pins.sql (51.71ms)22572026/10/01 07:39:18 OK 20260923120000_add_pushes.sql (42.05ms)22582026/10/01 07:39:18 goose: successfully migrated database to version: 2026092312000022592026/10/01 07:39:18 OK 1_commit_pending_closure.sql (2.18ms)22602026/10/01 07:39:18 OK 1_commit_pending_closure.sql (2.31ms)22612026/10/01 07:39:18 OK 2_object_stats_trigger.sql (450.96µs)22622026/10/01 07:39:18 OK 2_object_stats_trigger.sql (468.29µs)22632026/10/01 07:39:18 OK 3_commit_push.sql (397.79µs)22642026/10/01 07:39:18 goose: up to current file version: 322652026/10/01 07:39:18 OK 3_commit_push.sql (411.08µs)22662026/10/01 07:39:18 goose: up to current file version: 322672026/10/01 07:39:18 OK 20260628120000_add_object_size_and_stats.sql (56.09ms)22682026/10/01 07:39:18 OK 20260905000000_add_claims.sql (119.67ms)22692026/10/01 07:39:18 OK 20260920000000_drop_claims.sql (84.89ms)22702026/10/01 07:39:18 OK 20260923120000_add_pushes.sql (35.02ms)22712026/10/01 07:39:18 goose: successfully migrated database to version: 2026092312000022722026/10/01 07:39:18 OK 1_commit_pending_closure.sql (6.33ms)22732026/10/01 07:39:18 OK 2_object_stats_trigger.sql (1.04ms)22742026/10/01 07:39:18 OK 3_commit_push.sql (597.88µs)22752026/10/01 07:39:18 goose: up to current file version: 322762026-10-01 07:39:18.541 UTC [69361] ERROR: relation "goose_db_version" does not exist at character 3622772026-10-01 07:39:18.541 UTC [69361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22782026-10-01 07:39:18.782 UTC [69371] ERROR: relation "goose_db_version" does not exist at character 3622792026-10-01 07:39:18.782 UTC [69371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2280=== NAME TestNARDeduplicationMetadataUploadBug2281 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-67309-3657216313/TestNARDeduplicationMetadataUploadBug3593326605/001/store/n226h1nirv3knx98fkx8izv7fj5gvwd6-file1.txt22822026/10/01 07:39:18 OK 20241026095416_initial_model.sql (171.07ms)22832026/10/01 07:39:18 OK 20251210153512_drop_unused_gin_index.sql (4.17ms)22842026-10-01 07:39:18.841 UTC [69377] ERROR: relation "goose_db_version" does not exist at character 3622852026-10-01 07:39:18.841 UTC [69377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22862026/10/01 07:39:18 INFO Received push request method=POST path=/api/pushes22872026-10-01 07:39:18.872 UTC [69376] ERROR: relation "goose_db_version" does not exist at character 3622882026-10-01 07:39:18.872 UTC [69376] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22892026/10/01 07:39:18 OK 20251218171726_add_pins.sql (38.09ms)22902026/10/01 07:39:18 OK 20260628120000_add_object_size_and_stats.sql (66.57ms)22912026/10/01 07:39:18 INFO Received push request method=POST path=/api/pushes2292--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.84s)2293=== CONT TestGenerateLandingPage2294--- PASS: TestGenerateLandingPage (0.00s)2295=== CONT TestIsValidCachePath/narinfo2296=== CONT TestIsValidCachePath/index.html2297=== CONT TestIsValidCachePath/short_hash2298=== CONT TestIsValidCachePath/wrong_extension2299=== CONT TestIsValidCachePath/leading_slash2300=== CONT TestIsValidCachePath/empty2301=== CONT TestIsValidCachePath/random_path2302=== CONT TestIsValidCachePath/invalid_char_u2303=== CONT TestIsValidCachePath/invalid_char_e2304=== CONT TestIsValidCachePath/traversal_in_middle2305=== CONT TestIsValidCachePath/traversal_parent2306=== CONT TestIsValidCachePath/nar_uncompressed2307=== CONT TestIsValidCachePath/nix-cache-info2308=== CONT TestIsValidCachePath/realisation2309=== CONT TestIsValidCachePath/log2310=== CONT TestIsValidCachePath/ls2311=== CONT TestIsValidCachePath/nar_xz2312=== CONT TestIsValidCachePath/nar_bz22313=== CONT TestIsValidCachePath/nar_zst2314=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2315--- PASS: TestIsValidCachePath (0.00s)2316 --- PASS: TestIsValidCachePath/narinfo (0.00s)2317 --- PASS: TestIsValidCachePath/index.html (0.00s)2318 --- PASS: TestIsValidCachePath/short_hash (0.00s)2319 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2320 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2321 --- PASS: TestIsValidCachePath/empty (0.00s)2322 --- PASS: TestIsValidCachePath/random_path (0.00s)2323 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2324 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2325 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2326 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2327 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2328 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2329 --- PASS: TestIsValidCachePath/realisation (0.00s)2330 --- PASS: TestIsValidCachePath/log (0.00s)2331 --- PASS: TestIsValidCachePath/ls (0.00s)2332 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2333 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2334 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2335 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2336=== CONT TestParseSingleRange/none2337=== CONT TestParseSingleRange/open-ended2338=== CONT TestParseSingleRange/start_far_past_EOF2339=== CONT TestParseSingleRange/start_past_EOF2340=== CONT TestParseSingleRange/single_byte2341=== CONT TestParseSingleRange/suffix_exceeds_size2342=== CONT TestParseSingleRange/suffix2343=== CONT TestParseSingleRange/end_clamped_to_size2344=== CONT TestParseSingleRange/malformed_both_empty2345=== CONT TestParseSingleRange/closed2346=== CONT TestParseSingleRange/malformed_end_before_start2347=== CONT TestParseSingleRange/multi-range_ignored2348=== CONT TestParseSingleRange/malformed_no_dash2349=== CONT TestParseSingleRange/unknown_unit2350--- PASS: TestParseSingleRange (0.00s)2351 --- PASS: TestParseSingleRange/none (0.00s)2352 --- PASS: TestParseSingleRange/open-ended (0.00s)2353 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2354 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2355 --- PASS: TestParseSingleRange/single_byte (0.00s)2356 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2357 --- PASS: TestParseSingleRange/suffix (0.00s)2358 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2359 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2360 --- PASS: TestParseSingleRange/closed (0.00s)2361 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2362 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2363 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2364 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2365=== CONT TestServerTLSConfig/no_client_CA2366=== CONT TestServerTLSConfig/not_a_PEM_file23672026/10/01 07:39:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23682026/10/01 07:39:19 INFO Uploading n226h1nirv3knx98fkx8izv7fj5gvwd6-file1.txt (160B)2369=== CONT TestServerTLSConfig/missing_CA_file2370--- PASS: TestServerTLSConfig (0.00s)2371 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2372 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2373 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2374=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23752026/10/01 07:39:19 INFO Received uploads request method=POST path=/23762026/10/01 07:39:19 OK 20260905000000_add_claims.sql (109.52ms)23772026/10/01 07:39:19 WARN Failed to register uploaded object key=n226h1nirv3knx98fkx8izv7fj5gvwd6.ls error="server returned 404: 404 page not found\n"23782026/10/01 07:39:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23792026/10/01 07:39:19 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"23802026/10/01 07:39:19 INFO Signed narinfos id=1 count=123812026/10/01 07:39:19 INFO Uploading 1 narinfos23822026/10/01 07:39:19 INFO Received complete push request method=POST path=/api/pushes/1/complete23832026/10/01 07:39:19 WARN Failed to register uploaded object key=n226h1nirv3knx98fkx8izv7fj5gvwd6.narinfo error="server returned 404: 404 page not found\n"23842026/10/01 07:39:19 OK 20260920000000_drop_claims.sql (87.59ms)23852026/10/01 07:39:19 INFO Upload complete. (278ms)2386=== NAME TestNARDeduplicationMetadataUploadBug2387 metadata_upload_test.go:54: Retrieved narinfo from S3:2388 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestNARDeduplicationMetadataUploadBug3593326605/001/store/n226h1nirv3knx98fkx8izv7fj5gvwd6-file1.txt2389 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2390 Compression: zstd2391 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2392 NarSize: 1602393 References: 2394 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2395 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2396 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2397 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}23982026/10/01 07:39:19 OK 20241026095416_initial_model.sql (326.21ms)23992026/10/01 07:39:19 OK 20260923120000_add_pushes.sql (29.58ms)24002026/10/01 07:39:19 goose: successfully migrated database to version: 2026092312000024012026/10/01 07:39:19 OK 1_commit_pending_closure.sql (1.04ms)24022026/10/01 07:39:19 OK 2_object_stats_trigger.sql (280.38µs)24032026/10/01 07:39:19 OK 3_commit_push.sql (276.25µs)24042026/10/01 07:39:19 goose: up to current file version: 324052026/10/01 07:39:19 OK 20251210153512_drop_unused_gin_index.sql (13.59ms)24062026/10/01 07:39:19 OK 20251218171726_add_pins.sql (46.66ms)24072026/10/01 07:39:19 OK 20241026095416_initial_model.sql (346.04ms)24082026/10/01 07:39:19 OK 20260628120000_add_object_size_and_stats.sql (56.55ms)24092026/10/01 07:39:19 OK 20251210153512_drop_unused_gin_index.sql (13.85ms)24102026/10/01 07:39:19 INFO Received push request method=POST path=/api/pushes24112026/10/01 07:39:19 OK 20241026095416_initial_model.sql (312.66ms)2412=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info24132026/10/01 07:39:19 INFO Received uploads request method=POST path=/2414=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24152026/10/01 07:39:19 INFO Received request for more parts method=POST path=/2416=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart24172026/10/01 07:39:19 INFO Received complete multipart upload request method=POST path=/24182026/10/01 07:39:19 OK 20251210153512_drop_unused_gin_index.sql (28.19ms)2419=== NAME TestNARDeduplicationMetadataUploadBug2420 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-67309-3657216313/TestNARDeduplicationMetadataUploadBug3593326605/001/store/i8qvm6gvcvvgd9sxjgi1qv82rscxsvf5-file2.txt2421--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2422 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2423 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2424 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2425=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key24262026/10/01 07:39:19 INFO Received complete multipart upload request method=POST path=/2427=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key24282026/10/01 07:39:19 INFO Received request for more parts method=POST path=/2429=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal24302026/10/01 07:39:19 INFO Received uploads request method=POST path=/2431--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2432 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2433 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2434 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2435 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2436=== CONT TestIsValidUploadKey/narinfo2437=== CONT TestIsValidUploadKey/realisation_plus_in_output2438=== CONT TestIsValidUploadKey/realisation2439=== CONT TestIsValidUploadKey/nix-cache-info2440=== CONT TestIsValidUploadKey/build_log_equals2441=== CONT TestIsValidUploadKey/build_log_question_mark2442=== CONT TestIsValidUploadKey/build_log_plus_in_name2443=== CONT TestIsValidUploadKey/build_log_home-manager_file2444=== CONT TestIsValidUploadKey/build_log2445=== CONT TestIsValidUploadKey/listing2446=== CONT TestIsValidUploadKey/nar_plain2447=== CONT TestIsValidUploadKey/nar_xz2448=== CONT TestIsValidUploadKey/nar_zst2449=== CONT TestIsValidUploadKey/traversal2450=== CONT TestIsValidUploadKey/unknown_type2451=== CONT TestIsValidUploadKey/empty_key2452=== CONT TestIsValidUploadKey/absolute2453=== CONT TestIsValidUploadKey/traversal_nar2454=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2455=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2456=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2457=== CONT TestIsValidUploadKey/index.html2458--- PASS: TestIsValidUploadKey (0.00s)2459 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2460 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2461 --- PASS: TestIsValidUploadKey/realisation (0.00s)2462 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2463 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2464 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2465 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2466 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2467 --- PASS: TestIsValidUploadKey/build_log (0.00s)2468 --- PASS: TestIsValidUploadKey/listing (0.00s)2469 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2470 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2471 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2472 --- PASS: TestIsValidUploadKey/traversal (0.00s)2473 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2474 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2475 --- PASS: TestIsValidUploadKey/absolute (0.00s)2476 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2477 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2478 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2479 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2480 --- PASS: TestIsValidUploadKey/index.html (0.00s)2481=== CONT TestResolveDBConnectionString/flag_wins2482=== CONT TestResolveDBConnectionString/nothing_configured2483=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2484=== CONT TestResolveDBConnectionString/missing_file_is_an_error2485=== CONT TestResolveDBConnectionString/file_when_flag_empty2486=== CONT TestProxyWriteTimeout/narinfo2487=== CONT TestProxyWriteTimeout/10_GiB_nar2488=== CONT TestProxyWriteTimeout/unknown_size2489=== CONT TestProxyWriteTimeout/1_GiB_nar2490--- PASS: TestProxyWriteTimeout (0.00s)2491 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2492 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2493 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2494 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2495=== CONT TestClientErrorHandling/InvalidStorePath24962026/10/01 07:39:19 OK 20251218171726_add_pins.sql (75.47ms)2497--- PASS: TestResolveDBConnectionString (0.07s)2498 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2499 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2500 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2501 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2502 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)25032026/10/01 07:39:19 OK 20251218171726_add_pins.sql (57.39ms)25042026/10/01 07:39:19 INFO Received complete push request method=POST path=/api/pushes/1/complete25052026/10/01 07:39:19 OK 20260905000000_add_claims.sql (150.72ms)25062026/10/01 07:39:19 OK 20260628120000_add_object_size_and_stats.sql (87.81ms)25072026/10/01 07:39:19 INFO Received push request method=POST path=/api/pushes25082026/10/01 07:39:19 OK 20260920000000_drop_claims.sql (80ms)25092026/10/01 07:39:19 OK 20260923120000_add_pushes.sql (43.68ms)25102026/10/01 07:39:19 goose: successfully migrated database to version: 2026092312000025112026/10/01 07:39:19 OK 20260905000000_add_claims.sql (110.9ms)25122026/10/01 07:39:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)25132026/10/01 07:39:19 OK 1_commit_pending_closure.sql (1.19ms)25142026/10/01 07:39:19 OK 2_object_stats_trigger.sql (300.29µs)25152026/10/01 07:39:19 OK 3_commit_push.sql (241.71µs)25162026/10/01 07:39:19 goose: up to current file version: 32517--- PASS: TestPush_CompleteCommitsEveryRoot (6.15s)2518=== CONT TestClientErrorHandling/InvalidAuthToken25192026/10/01 07:39:19 OK 20260628120000_add_object_size_and_stats.sql (180.79ms)25202026/10/01 07:39:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign25212026/10/01 07:39:19 INFO Signed narinfos id=2 count=125222026/10/01 07:39:19 WARN Failed to register uploaded object key=i8qvm6gvcvvgd9sxjgi1qv82rscxsvf5.ls error="server returned 404: 404 page not found\n"25232026/10/01 07:39:19 INFO Uploading 1 narinfos25242026/10/01 07:39:19 OK 20260920000000_drop_claims.sql (105.93ms)25252026/10/01 07:39:19 INFO Received complete push request method=POST path=/api/pushes/2/complete25262026/10/01 07:39:19 WARN Failed to register uploaded object key=i8qvm6gvcvvgd9sxjgi1qv82rscxsvf5.narinfo error="server returned 404: 404 page not found\n"25272026/10/01 07:39:19 INFO Upload complete. (283ms)2528=== NAME TestNARDeduplicationMetadataUploadBug2529 metadata_upload_test.go:76: Retrieved narinfo from S3:2530 StorePath: /nix/var/nix/builds/nix-67309-3657216313/TestNARDeduplicationMetadataUploadBug3593326605/001/store/i8qvm6gvcvvgd9sxjgi1qv82rscxsvf5-file2.txt2531 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2532 Compression: zstd2533 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2534 NarSize: 1602535 References: 2536 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2537 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2538 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2539 {"version":1,"root":{"type":"regular","size":44}}25402026/10/01 07:39:19 OK 20260923120000_add_pushes.sql (28.21ms)25412026/10/01 07:39:19 goose: successfully migrated database to version: 2026092312000025422026/10/01 07:39:19 OK 1_commit_pending_closure.sql (1.36ms)25432026/10/01 07:39:19 OK 2_object_stats_trigger.sql (330.25µs)25442026/10/01 07:39:19 OK 3_commit_push.sql (263.83µs)25452026/10/01 07:39:19 goose: up to current file version: 325462026/10/01 07:39:19 OK 20260905000000_add_claims.sql (147.7ms)2547=== RUN TestService_RequireScope_OIDC/builder_may_write2548=== PAUSE TestService_RequireScope_OIDC/builder_may_write2549=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2550=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2551=== RUN TestService_RequireScope_OIDC/ops_may_admin2552=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2553=== RUN TestService_RequireScope_OIDC/ops_may_not_write2554=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2555=== RUN TestService_RequireScope_OIDC/reader_may_not_write2556=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2557=== RUN TestService_RequireScope_OIDC/static_token_may_admin2558=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2559=== RUN TestService_RequireScope_OIDC/static_token_may_write2560=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2561=== RUN TestService_RequireScope_OIDC/reader_may_read2562=== PAUSE TestService_RequireScope_OIDC/reader_may_read2563=== RUN TestService_RequireScope_OIDC/writer_implies_read2564=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2565=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2566=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2567=== CONT TestClientErrorHandling/ServerNotAvailable25682026/10/01 07:39:19 OK 20260920000000_drop_claims.sql (128.83ms)25692026/10/01 07:39:19 OK 20260923120000_add_pushes.sql (39.62ms)25702026/10/01 07:39:19 goose: successfully migrated database to version: 2026092312000025712026/10/01 07:39:19 OK 1_commit_pending_closure.sql (1.78ms)25722026/10/01 07:39:19 OK 2_object_stats_trigger.sql (386.88µs)25732026/10/01 07:39:19 OK 3_commit_push.sql (355.46µs)25742026/10/01 07:39:19 goose: up to current file version: 32575--- PASS: TestNARDeduplicationMetadataUploadBug (6.87s)2576=== CONT TestPush_RejectsBadRequests/no_roots25772026/10/01 07:39:19 INFO Received push request method=POST path=/api/pushes2578=== CONT TestPush_RejectsBadRequests/bad_root25792026/10/01 07:39:19 INFO Received push request method=POST path=/api/pushes2580=== CONT TestPush_RejectsBadRequests/no_objects25812026/10/01 07:39:19 INFO Received push request method=POST path=/api/pushes2582=== CONT TestPush_RejectsBadRequests/root_not_in_objects25832026/10/01 07:39:19 INFO Received push request method=POST path=/api/pushes2584=== CONT TestCacheConfigHandler/full_config,_no_issuer2585--- PASS: TestPush_RejectsBadRequests (3.11s)2586 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2587 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2588 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2589 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2590=== CONT TestCacheConfigHandler/no_signing_keys2591=== CONT TestCacheConfigHandler/no_cache_url_configured2592=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2593--- PASS: TestCacheConfigHandler (0.00s)2594 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2595 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2596 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2597 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2598=== CONT TestService_RequireScope_OIDC/builder_may_write2599=== CONT TestService_RequireScope_OIDC/static_token_may_admin2600=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2601=== CONT TestService_RequireScope_OIDC/writer_implies_read2602=== CONT TestService_RequireScope_OIDC/reader_may_read2603=== CONT TestService_RequireScope_OIDC/static_token_may_write2604=== CONT TestService_RequireScope_OIDC/ops_may_not_write2605=== CONT TestService_RequireScope_OIDC/reader_may_not_write2606=== CONT TestService_RequireScope_OIDC/ops_may_admin2607=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2608--- PASS: TestService_RequireScope_OIDC (5.45s)2609 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2610 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2611 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2612 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2613 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2614 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2615 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2616 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2617 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2618 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2619--- PASS: TestCacheStatsHandler (5.71s)26202026/10/01 07:39:20 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/present26212026/10/01 07:39:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.9159ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26222026-10-01 07:39:20.618 UTC [69406] ERROR: relation "goose_db_version" does not exist at character 3626232026-10-01 07:39:20.618 UTC [69406] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26242026/10/01 07:39:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.800311ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26252026/10/01 07:39:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26262026/10/01 07:39:20 WARN mTLS auth: bound subjects configured but subject DN unavailable26272026/10/01 07:39:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2628--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.00s)26292026/10/01 07:39:21 OK 20241026095416_initial_model.sql (413.04ms)26302026/10/01 07:39:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=784.420407ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26312026/10/01 07:39:21 OK 20251210153512_drop_unused_gin_index.sql (25.34ms)26322026/10/01 07:39:21 OK 20251218171726_add_pins.sql (60.33ms)26332026/10/01 07:39:21 OK 20260628120000_add_object_size_and_stats.sql (63.74ms)2634=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2635=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2636=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2637=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2638=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2639=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2640=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2641=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2642=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2643=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2644=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26452026/10/01 07:39:21 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2646=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured26472026/10/01 07:39:21 WARN Authentication failed token_preview=eyJhbGciOi...fv5Gvko5BQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2648--- PASS: TestService_AuthMiddleware_OIDC (6.63s)2649 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2650 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2651 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2652 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)26532026/10/01 07:39:21 OK 20260905000000_add_claims.sql (185.97ms)26542026/10/01 07:39:21 OK 20260920000000_drop_claims.sql (129.32ms)26552026/10/01 07:39:21 OK 20260923120000_add_pushes.sql (39.2ms)26562026/10/01 07:39:21 goose: successfully migrated database to version: 2026092312000026572026/10/01 07:39:21 OK 1_commit_pending_closure.sql (2.78ms)26582026/10/01 07:39:21 OK 2_object_stats_trigger.sql (559.96µs)26592026/10/01 07:39:21 OK 3_commit_push.sql (361.88µs)26602026/10/01 07:39:21 goose: up to current file version: 326612026/10/01 07:39:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.693186358s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26622026-10-01 07:39:21.990 UTC [69441] ERROR: relation "goose_db_version" does not exist at character 3626632026-10-01 07:39:21.990 UTC [69441] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2664--- PASS: TestService_ReadAuthMiddleware (6.07s)26652026-10-01 07:39:22.539 UTC [69445] ERROR: relation "goose_db_version" does not exist at character 3626662026-10-01 07:39:22.539 UTC [69445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26672026/10/01 07:39:22 OK 20241026095416_initial_model.sql (419.7ms)26682026/10/01 07:39:22 OK 20251210153512_drop_unused_gin_index.sql (16.66ms)26692026/10/01 07:39:22 OK 20251218171726_add_pins.sql (48.32ms)26702026/10/01 07:39:22 OK 20260628120000_add_object_size_and_stats.sql (57.39ms)26712026/10/01 07:39:22 OK 20260905000000_add_claims.sql (62.08ms)26722026/10/01 07:39:22 OK 20260920000000_drop_claims.sql (52.43ms)26732026/10/01 07:39:22 OK 20260923120000_add_pushes.sql (6.61ms)26742026/10/01 07:39:22 goose: successfully migrated database to version: 2026092312000026752026/10/01 07:39:22 OK 1_commit_pending_closure.sql (1.62ms)26762026/10/01 07:39:22 OK 2_object_stats_trigger.sql (369.63µs)26772026/10/01 07:39:22 OK 3_commit_push.sql (308.58µs)26782026/10/01 07:39:22 goose: up to current file version: 326792026/10/01 07:39:22 OK 20241026095416_initial_model.sql (180.1ms)26802026/10/01 07:39:22 OK 20251210153512_drop_unused_gin_index.sql (28.03ms)26812026/10/01 07:39:22 OK 20251218171726_add_pins.sql (54.22ms)26822026/10/01 07:39:22 OK 20260628120000_add_object_size_and_stats.sql (56.55ms)26832026/10/01 07:39:23 OK 20260905000000_add_claims.sql (132.54ms)26842026/10/01 07:39:23 OK 20260920000000_drop_claims.sql (107.17ms)2685--- PASS: TestService_ReadScope_PublicByDefault (5.92s)26862026/10/01 07:39:23 OK 20260923120000_add_pushes.sql (43.13ms)26872026/10/01 07:39:23 goose: successfully migrated database to version: 2026092312000026882026/10/01 07:39:23 OK 1_commit_pending_closure.sql (4.85ms)26892026/10/01 07:39:23 OK 2_object_stats_trigger.sql (1.04ms)26902026/10/01 07:39:23 OK 3_commit_push.sql (1.88ms)26912026/10/01 07:39:23 goose: up to current file version: 32692--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.32s)26932026/10/01 07:39:23 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-config26942026/10/01 07:39:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.959822ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26952026/10/01 07:39:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.60292ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26962026-10-01 07:39:24.097 UTC [69467] ERROR: relation "goose_db_version" does not exist at character 3626972026-10-01 07:39:24.097 UTC [69467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26982026-10-01 07:39:24.132 UTC [69469] ERROR: relation "goose_db_version" does not exist at character 3626992026-10-01 07:39:24.132 UTC [69469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27002026/10/01 07:39:24 OK 20241026095416_initial_model.sql (132.86ms)27012026/10/01 07:39:24 OK 20251210153512_drop_unused_gin_index.sql (7.95ms)27022026/10/01 07:39:24 OK 20241026095416_initial_model.sql (114.26ms)27032026/10/01 07:39:24 OK 20251218171726_add_pins.sql (7.2ms)27042026/10/01 07:39:24 OK 20251210153512_drop_unused_gin_index.sql (9.17ms)27052026/10/01 07:39:24 OK 20260628120000_add_object_size_and_stats.sql (24.53ms)27062026/10/01 07:39:24 OK 20251218171726_add_pins.sql (24.32ms)27072026/10/01 07:39:24 OK 20260628120000_add_object_size_and_stats.sql (20.06ms)27082026/10/01 07:39:24 OK 20260905000000_add_claims.sql (36.42ms)27092026/10/01 07:39:24 OK 20260920000000_drop_claims.sql (59.95ms)27102026/10/01 07:39:24 OK 20260905000000_add_claims.sql (67.47ms)27112026/10/01 07:39:24 OK 20260923120000_add_pushes.sql (12.6ms)27122026/10/01 07:39:24 goose: successfully migrated database to version: 2026092312000027132026/10/01 07:39:24 OK 1_commit_pending_closure.sql (1.55ms)27142026/10/01 07:39:24 OK 2_object_stats_trigger.sql (235.79µs)27152026/10/01 07:39:24 OK 3_commit_push.sql (216µs)27162026/10/01 07:39:24 goose: up to current file version: 327172026/10/01 07:39:24 OK 20260920000000_drop_claims.sql (39.93ms)27182026/10/01 07:39:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=819.743632ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27192026/10/01 07:39:24 OK 20260923120000_add_pushes.sql (18.47ms)27202026/10/01 07:39:24 goose: successfully migrated database to version: 2026092312000027212026/10/01 07:39:24 OK 1_commit_pending_closure.sql (1.06ms)27222026/10/01 07:39:24 OK 2_object_stats_trigger.sql (241.71µs)27232026/10/01 07:39:24 OK 3_commit_push.sql (227.54µs)27242026/10/01 07:39:24 goose: up to current file version: 327252026/10/01 07:39:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.637891814s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27262026/10/01 07:39:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27272026/10/01 07:39:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27282026/10/01 07:39:26 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"27292026/10/01 07:39:26 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-config27302026/10/01 07:39:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.797883ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27312026/10/01 07:39:27 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.863984ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27322026/10/01 07:39:27 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=845.213167ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27332026/10/01 07:39:28 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.55191978s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27342026/10/01 07:39:29 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_closures27352026/10/01 07:39:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.26954ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27362026/10/01 07:39:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.860379ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27372026/10/01 07:39:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=806.304819ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27382026/10/01 07:39:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.726072644s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2739--- PASS: TestClientErrorHandling (0.00s)2740 --- PASS: TestClientErrorHandling/InvalidStorePath (5.55s)2741 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.37s)2742 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.44s)2743PASS2744{"timestamp":"2026-10-01T07:39:33.261673Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57754","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}27452026-10-01 07:39:37.533 UTC [67974] LOG: received smart shutdown request27462026-10-01 07:39:37.534 UTC [67974] LOG: background worker "logical replication launcher" (PID 67990) exited with exit code 127472026-10-01 07:39:37.758 UTC [67984] LOG: shutting down27482026-10-01 07:39:37.758 UTC [67984] LOG: checkpoint starting: shutdown immediate27492026/10/01 07:39:43 ERROR failed to kill rustfs error="no such process"27502026-10-01 07:39:43.538 UTC [67984] LOG: checkpoint complete: wrote 12662 buffers (77.3%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 20 recycled; write=5.136 s, sync=0.607 s, total=5.781 s; sync files=23922, longest=0.021 s, average=0.001 s; distance=331075 kB, estimate=331075 kB; lsn=0/15ADDCA8, redo lsn=0/15ADDCA827512026-10-01 07:39:43.545 UTC [67974] LOG: database system is shut down2752Running OIDC tests...2753=== RUN TestAudienceForIssuer2754=== PAUSE TestAudienceForIssuer2755=== RUN TestGlobMatch2756=== PAUSE TestGlobMatch2757=== RUN TestValidateToken_ValidToken2758=== PAUSE TestValidateToken_ValidToken2759=== RUN TestValidateToken_WrongAudience2760=== PAUSE TestValidateToken_WrongAudience2761=== RUN TestValidateToken_Expired2762=== PAUSE TestValidateToken_Expired2763=== RUN TestValidateToken_BoundClaimsMismatch2764=== PAUSE TestValidateToken_BoundClaimsMismatch2765=== RUN TestValidateToken_BoundSubjectMismatch2766=== PAUSE TestValidateToken_BoundSubjectMismatch2767=== RUN TestValidateToken_MultipleProviders2768=== PAUSE TestValidateToken_MultipleProviders2769=== RUN TestValidateToken_NoMatchingProvider2770=== PAUSE TestValidateToken_NoMatchingProvider2771=== RUN TestValidateToken_KubernetesServiceAccount2772=== PAUSE TestValidateToken_KubernetesServiceAccount2773=== RUN TestNewValidator_KubernetesRequiresCA2774=== PAUSE TestNewValidator_KubernetesRequiresCA2775=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2776=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2777=== RUN TestPins_ReservedForMatchingRule2778=== PAUSE TestPins_ReservedForMatchingRule2779=== RUN TestPins_TopLevelShorthand2780=== PAUSE TestPins_TopLevelShorthand2781=== RUN TestPins_ConfigValidation2782=== PAUSE TestPins_ConfigValidation2783=== RUN TestScopes_LegacyProviderDefaultsToWrite2784=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2785=== RUN TestScopes_Rules2786=== PAUSE TestScopes_Rules2787=== RUN TestScopes_ConfigValidation2788=== PAUSE TestScopes_ConfigValidation2789=== CONT TestAudienceForIssuer2790--- PASS: TestAudienceForIssuer (0.00s)2791=== CONT TestValidateToken_Expired2792=== CONT TestValidateToken_BoundClaimsMismatch2793=== CONT TestValidateToken_KubernetesServiceAccount2794=== CONT TestPins_ConfigValidation2795=== CONT TestValidateToken_ValidToken2796=== CONT TestGlobMatch2797=== RUN TestGlobMatch/foo_foo2798=== CONT TestValidateToken_WrongAudience2799=== PAUSE TestGlobMatch/foo_foo2800=== CONT TestScopes_Rules2801=== CONT TestScopes_ConfigValidation2802=== CONT TestValidateToken_NoMatchingProvider2803=== RUN TestGlobMatch/foo_bar2804=== PAUSE TestGlobMatch/foo_bar2805=== RUN TestGlobMatch/*_2806=== PAUSE TestGlobMatch/*_2807=== RUN TestGlobMatch/*_anything2808=== PAUSE TestGlobMatch/*_anything2809=== RUN TestGlobMatch/foo*_foo2810=== PAUSE TestGlobMatch/foo*_foo2811=== RUN TestGlobMatch/foo*_foobar2812=== PAUSE TestGlobMatch/foo*_foobar2813=== RUN TestGlobMatch/foo*_bar2814=== PAUSE TestGlobMatch/foo*_bar2815=== RUN TestGlobMatch/*bar_bar2816=== PAUSE TestGlobMatch/*bar_bar2817=== RUN TestGlobMatch/*bar_foobar2818=== PAUSE TestGlobMatch/*bar_foobar2819=== RUN TestGlobMatch/*bar_foo2820=== PAUSE TestGlobMatch/*bar_foo2821=== RUN TestGlobMatch/foo*bar_foobar2822=== PAUSE TestGlobMatch/foo*bar_foobar2823=== RUN TestGlobMatch/foo*bar_foo123bar2824=== PAUSE TestGlobMatch/foo*bar_foo123bar2825=== RUN TestGlobMatch/foo*bar_foobarbaz2826=== PAUSE TestGlobMatch/foo*bar_foobarbaz2827=== RUN TestGlobMatch/*/*_foo/bar2828=== PAUSE TestGlobMatch/*/*_foo/bar2829=== RUN TestGlobMatch/*/*_foo2830=== PAUSE TestGlobMatch/*/*_foo2831=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2832=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2833=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02834=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02835=== RUN TestGlobMatch/refs/*/main_refs/heads/main2836=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2837=== RUN TestGlobMatch/fo?_foo2838=== PAUSE TestGlobMatch/fo?_foo2839=== RUN TestGlobMatch/fo?_fo2840=== PAUSE TestGlobMatch/fo?_fo2841=== RUN TestGlobMatch/fo?_fooo2842=== PAUSE TestGlobMatch/fo?_fooo2843=== RUN TestGlobMatch/?oo_foo2844=== PAUSE TestGlobMatch/?oo_foo2845=== RUN TestGlobMatch/?oo_boo2846=== PAUSE TestGlobMatch/?oo_boo2847=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2848=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2849=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2850=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2851=== CONT TestScopes_LegacyProviderDefaultsToWrite2852--- PASS: TestPins_ConfigValidation (0.00s)2853=== CONT TestPins_ReservedForMatchingRule2854--- PASS: TestScopes_ConfigValidation (0.00s)2855=== CONT TestPins_TopLevelShorthand28562026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58544/oidc2857--- PASS: TestValidateToken_ValidToken (0.01s)2858=== CONT TestValidateToken_KubernetesIssuerFromOwnToken28592026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58546/oidc2860--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2861=== CONT TestNewValidator_KubernetesRequiresCA28622026/10/01 07:39:45 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:585482863--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)2864=== CONT TestValidateToken_BoundSubjectMismatch28652026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58551/oidc2866--- PASS: TestPins_ReservedForMatchingRule (0.04s)2867=== CONT TestValidateToken_MultipleProviders28682026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58553/oidc2869--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)2870=== CONT TestGlobMatch/foo_foo2871=== CONT TestGlobMatch/*/*_foo/bar2872=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2873=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2874=== CONT TestGlobMatch/?oo_boo2875=== CONT TestGlobMatch/?oo_foo2876=== CONT TestGlobMatch/fo?_fooo2877=== CONT TestGlobMatch/fo?_fo2878=== CONT TestGlobMatch/fo?_foo2879=== CONT TestGlobMatch/refs/*/main_refs/heads/main2880=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02881=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2882=== CONT TestGlobMatch/*/*_foo2883=== CONT TestGlobMatch/*bar_bar2884=== CONT TestGlobMatch/foo*bar_foobarbaz2885=== CONT TestGlobMatch/foo*bar_foo123bar2886=== CONT TestGlobMatch/foo*bar_foobar2887=== CONT TestGlobMatch/*bar_foo2888=== CONT TestGlobMatch/*bar_foobar2889=== CONT TestGlobMatch/foo*_foo2890=== CONT TestGlobMatch/foo*_bar2891=== CONT TestGlobMatch/foo*_foobar2892=== CONT TestGlobMatch/*_2893=== CONT TestGlobMatch/*_anything2894=== CONT TestGlobMatch/foo_bar2895--- PASS: TestGlobMatch (0.00s)2896 --- PASS: TestGlobMatch/foo_foo (0.00s)2897 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2898 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2899 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2900 --- PASS: TestGlobMatch/?oo_boo (0.00s)2901 --- PASS: TestGlobMatch/?oo_foo (0.00s)2902 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2903 --- PASS: TestGlobMatch/fo?_fo (0.00s)2904 --- PASS: TestGlobMatch/fo?_foo (0.00s)2905 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2906 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2907 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2908 --- PASS: TestGlobMatch/*/*_foo (0.00s)2909 --- PASS: TestGlobMatch/*bar_bar (0.00s)2910 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2911 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2912 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2913 --- PASS: TestGlobMatch/*bar_foo (0.00s)2914 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2915 --- PASS: TestGlobMatch/foo*_foo (0.00s)2916 --- PASS: TestGlobMatch/foo*_bar (0.00s)2917 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2918 --- PASS: TestGlobMatch/*_ (0.00s)2919 --- PASS: TestGlobMatch/*_anything (0.00s)2920 --- PASS: TestGlobMatch/foo_bar (0.00s)29212026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58555/oidc29222026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58557/oidc2923--- PASS: TestValidateToken_Expired (0.05s)29242026/10/01 07:39:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58550/oidc2925--- PASS: TestScopes_Rules (0.05s)2926--- PASS: TestValidateToken_NoMatchingProvider (0.05s)29272026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58563/oidc2928--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)29292026/10/01 07:39:45 http: TLS handshake error from 127.0.0.1:58562: remote error: tls: bad certificate2930--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)29312026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58565/oidc29322026/10/01 07:39:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58567/oidc2933--- PASS: TestValidateToken_WrongAudience (0.06s)2934--- PASS: TestPins_TopLevelShorthand (0.06s)29352026/10/01 07:39:45 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232936--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)29372026/10/01 07:39:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:58572/oidc29382026/10/01 07:39:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58571/oidc2939--- PASS: TestValidateToken_MultipleProviders (0.07s)2940PASS2941Running hook tests...2942=== RUN TestSendPathsEmpty2943=== PAUSE TestSendPathsEmpty2944=== RUN TestQueueEnqueueAndFetch2945=== PAUSE TestQueueEnqueueAndFetch2946=== RUN TestQueueDeduplication2947=== PAUSE TestQueueDeduplication2948=== RUN TestQueueRemove2949=== PAUSE TestQueueRemove2950=== RUN TestQueueFetchBatchLimit2951=== PAUSE TestQueueFetchBatchLimit2952=== RUN TestQueueRetryMovesToBack2953=== PAUSE TestQueueRetryMovesToBack2954=== RUN TestQueueFetchRemoveLifecycle2955=== PAUSE TestQueueFetchRemoveLifecycle2956=== RUN TestQueueConcurrentWriters2957=== PAUSE TestQueueConcurrentWriters2958=== RUN TestQueueRemoveLargeClosure2959=== PAUSE TestQueueRemoveLargeClosure2960=== RUN TestServerClientIntegration2961=== PAUSE TestServerClientIntegration2962=== RUN TestServerQueueError2963=== PAUSE TestServerQueueError2964=== RUN TestGetListenerSocketActivation2965 server_test.go:210: === RUN TestGetListenerSocketActivation2966 --- PASS: TestGetListenerSocketActivation (0.00s)2967 PASS2968 2969--- PASS: TestGetListenerSocketActivation (0.01s)2970=== RUN TestDrainIsolatesPoisonPath2971=== PAUSE TestDrainIsolatesPoisonPath2972=== RUN TestRunNotBlockedByPoisonHead2973=== PAUSE TestRunNotBlockedByPoisonHead2974=== RUN TestDrainGivesUpWhenServerDown2975=== PAUSE TestDrainGivesUpWhenServerDown2976=== RUN TestFailedPathPrunedByLaterClosure2977=== PAUSE TestFailedPathPrunedByLaterClosure2978=== RUN TestWorkerUploadsAndRemoves2979=== PAUSE TestWorkerUploadsAndRemoves2980=== RUN TestWorkerSkipsGCdPaths2981=== PAUSE TestWorkerSkipsGCdPaths2982=== RUN TestWorkerPrunesClosureDeps2983=== PAUSE TestWorkerPrunesClosureDeps2984=== RUN TestDrainTimeout2985=== PAUSE TestDrainTimeout2986=== CONT TestSendPathsEmpty2987=== CONT TestServerQueueError2988--- PASS: TestSendPathsEmpty (0.00s)2989=== CONT TestQueueFetchBatchLimit2990=== CONT TestQueueRetryMovesToBack2991=== CONT TestQueueRemoveLargeClosure2992=== CONT TestQueueConcurrentWriters2993=== CONT TestServerClientIntegration2994=== CONT TestWorkerUploadsAndRemoves2995=== CONT TestQueueDeduplication2996=== CONT TestQueueFetchRemoveLifecycle2997=== CONT TestWorkerPrunesClosureDeps29982026/10/01 07:39:45 ERROR Failed to queue paths error="permission denied" count=12999--- PASS: TestServerQueueError (0.00s)3000=== CONT TestQueueRemove3001--- PASS: TestServerClientIntegration (0.00s)3002=== CONT TestWorkerSkipsGCdPaths30032026/10/01 07:39:45 INFO Upload queue status pending=230042026/10/01 07:39:45 INFO Uploading batch count=23005--- PASS: TestQueueFetchBatchLimit (0.01s)3006=== CONT TestDrainGivesUpWhenServerDown3007--- PASS: TestQueueRemove (0.01s)3008=== CONT TestFailedPathPrunedByLaterClosure30092026/10/01 07:39:45 INFO Upload queue status pending=230102026/10/01 07:39:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-67309-3657216313/TestWorkerSkipsGCdPaths4068617192/002/nonexistent3011--- PASS: TestQueueDeduplication (0.01s)3012=== CONT TestDrainTimeout3013--- PASS: TestQueueRetryMovesToBack (0.01s)3014=== CONT TestRunNotBlockedByPoisonHead30152026/10/01 07:39:45 INFO Upload queue status pending=230162026/10/01 07:39:45 INFO Uploading batch count=130172026/10/01 07:39:45 INFO Uploading batch count=13018--- PASS: TestQueueFetchRemoveLifecycle (0.01s)3019=== CONT TestDrainIsolatesPoisonPath30202026/10/01 07:39:45 INFO Uploading batch count=230212026/10/01 07:39:45 INFO Uploading batch count=130222026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=130232026/10/01 07:39:45 INFO Uploading batch count=130242026/10/01 07:39:45 INFO Uploading batch count=130252026/10/01 07:39:45 INFO Uploading batch count=430262026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=430272026/10/01 07:39:45 INFO Uploading batch count=230282026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=230292026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainGivesUpWhenServerDown3640929657/002/a30302026/10/01 07:39:45 INFO Upload queue status pending=330312026/10/01 07:39:45 INFO Uploading batch count=130322026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=130332026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainIsolatesPoisonPath895587161/002/bbb30342026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainGivesUpWhenServerDown3640929657/002/b30352026/10/01 07:39:45 INFO Uploading batch count=230362026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=230372026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainGivesUpWhenServerDown3640929657/002/c30382026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainGivesUpWhenServerDown3640929657/002/d3039--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)3040=== CONT TestQueueEnqueueAndFetch30412026/10/01 07:39:45 INFO Uploading batch count=130422026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=130432026/10/01 07:39:45 INFO Uploading batch count=230442026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=230452026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainGivesUpWhenServerDown3640929657/002/e30462026/10/01 07:39:45 INFO Uploading batch count=130472026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=130482026/10/01 07:39:45 INFO Uploading batch count=130492026/10/01 07:39:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-67309-3657216313/TestDrainGivesUpWhenServerDown3640929657/002/f30502026/10/01 07:39:45 ERROR Upload failed error="upload failed" count=130512026/10/01 07:39:45 ERROR Drain finished with paths left in queue remaining=1030522026/10/01 07:39:45 ERROR Drain finished with paths left in queue remaining=13053--- PASS: TestDrainIsolatesPoisonPath (0.01s)3054--- PASS: TestDrainGivesUpWhenServerDown (0.01s)3055--- PASS: TestQueueEnqueueAndFetch (0.00s)3056--- PASS: TestWorkerUploadsAndRemoves (0.03s)3057--- PASS: TestWorkerSkipsGCdPaths (0.03s)3058--- PASS: TestWorkerPrunesClosureDeps (0.03s)3059--- PASS: TestQueueRemoveLargeClosure (0.05s)3060--- PASS: TestQueueConcurrentWriters (0.15s)30612026/10/01 07:39:45 ERROR Upload failed error="context deadline exceeded" count=230622026/10/01 07:39:45 ERROR Drain finished with paths left in queue remaining=43063--- PASS: TestDrainTimeout (0.20s)30642026/10/01 07:39:46 INFO Uploading batch count=130652026/10/01 07:39:46 INFO Uploading batch count=130662026/10/01 07:39:46 INFO Uploading batch count=130672026/10/01 07:39:46 ERROR Upload failed error="upload failed" count=130682026/10/01 07:39:46 INFO Uploading batch count=130692026/10/01 07:39:46 ERROR Upload failed error="upload failed" count=130702026/10/01 07:39:46 INFO Uploading batch count=130712026/10/01 07:39:46 ERROR Upload failed error="upload failed" count=130722026/10/01 07:39:46 INFO Uploading batch count=130732026/10/01 07:39:46 ERROR Upload failed error="upload failed" count=130742026/10/01 07:39:46 ERROR Drain finished with paths left in queue remaining=13075--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3076PASS