niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #268
· 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.03s)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--- PASS: TestShellSplit (0.00s)97=== CONT TestFileTokenMissing98=== CONT TestSetClientTLSErrors99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestFileTokenReadsAndCaches102=== CONT TestScriptTokenScriptFails103--- PASS: TestFileTokenMissing (0.00s)104=== CONT TestStaticToken105--- PASS: TestStaticToken (0.00s)106=== CONT TestStreamPushRequestLine107=== CONT TestScriptTokenEmptyToken108=== CONT TestScriptTokenBadJSON109=== CONT TestScriptTokenNoExpiryRerunsEveryCall1102026/09/23 13:29:16 ERROR Upload failed error=boom count=1111=== CONT TestScriptTokenCachesUntilRefresh112=== CONT TestFileTokenEmpty113=== RUN TestSetClientTLSErrors/missing_cert_file114=== PAUSE TestSetClientTLSErrors/missing_cert_file115=== RUN TestSetClientTLSErrors/missing_key_file116=== PAUSE TestSetClientTLSErrors/missing_key_file117=== RUN TestSetClientTLSErrors/missing_ca_file118=== PAUSE TestSetClientTLSErrors/missing_ca_file119=== RUN TestSetClientTLSErrors/invalid_ca_file120=== PAUSE TestSetClientTLSErrors/invalid_ca_file121=== CONT TestSetClientTLSDoesNotMutateDefaultTransport122--- PASS: TestFileTokenReadsAndCaches (0.00s)123=== CONT TestSetClientTLS124--- PASS: TestFileTokenEmpty (0.00s)125=== CONT TestClientSignaturesByStorePath126--- PASS: TestDoServerRequestAttachesToken (0.00s)127=== CONT TestStreamPushReportsSignatures128--- PASS: TestClientSignaturesByStorePath (0.00s)129=== CONT TestEncodeNixBase32WithRealHash130--- PASS: TestEncodeNixBase32WithRealHash (0.00s)131=== CONT TestDoWithRetry_BodyReplayedViaGetBody1322026/09/23 13:29:16 ERROR Upload failed error=boom count=1133--- PASS: TestStreamPushReportsSignatures (0.00s)134=== CONT TestResolveStorePath135--- PASS: TestScriptTokenScriptFails (0.00s)136=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1372026/09/23 13:29:16 WARN Rate limiter enabled after throttle name=server-test rate=5138--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)139=== CONT TestRateLimiterFeedback140=== RUN TestRateLimiterFeedback/429_enables_limiter141=== PAUSE TestRateLimiterFeedback/429_enables_limiter142=== RUN TestRateLimiterFeedback/503_enables_limiter143=== PAUSE TestRateLimiterFeedback/503_enables_limiter144=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter145=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter146=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter147=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter148=== CONT TestPathInfoCACompatibility149=== RUN TestPathInfoCACompatibility/null_ca_field150=== PAUSE TestPathInfoCACompatibility/null_ca_field151=== RUN TestPathInfoCACompatibility/old_string_format_-_text152--- PASS: TestResolveStorePath (0.00s)153=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text154=== CONT TestParsePathInfoJSONMultiplePaths155=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive156=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive157=== RUN TestPathInfoCACompatibility/new_structured_format_-_text158=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text159=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths162=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method165=== 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=== CONT TestPathInfoHashCompatibility174=== PAUSE TestParsePathInfoJSON/whitespace_only175=== RUN TestParsePathInfoJSON/invalid_JSON176=== PAUSE TestParsePathInfoJSON/invalid_JSON177=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)178=== CONT TestGetStorePathHash179=== RUN TestGetStorePathHash/valid_store_path180=== PAUSE TestGetStorePathHash/valid_store_path181=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error183=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon184=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error185=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon186=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI187=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI188=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512189=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512190=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error191=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error192=== CONT TestConvertHashToNix32193=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error194=== RUN TestConvertHashToNix32/SRI_format_to_Nix32195=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error196=== CONT TestUploadMultipart_SupersededByPeer197=== RUN TestUploadMultipart_SupersededByPeer/exists198=== PAUSE TestUploadMultipart_SupersededByPeer/exists199=== RUN TestUploadMultipart_SupersededByPeer/missing200=== PAUSE TestUploadMultipart_SupersededByPeer/missing201=== CONT TestEncodeNixBase32202=== RUN TestEncodeNixBase32/test_string_hash203=== PAUSE TestEncodeNixBase32/test_string_hash204=== RUN TestEncodeNixBase32/empty_input205=== PAUSE TestEncodeNixBase32/empty_input206=== CONT TestDumpPathWriterError207=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix322082026/09/23 13:29:16 WARN Rate limiter enabled after throttle name=server-test rate=5209=== RUN TestConvertHashToNix32/already_Nix32_format2102026/09/23 13:29:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58644211=== PAUSE TestConvertHashToNix32/already_Nix32_format212=== RUN TestConvertHashToNix32/invalid_format213=== PAUSE TestConvertHashToNix32/invalid_format214=== CONT TestDumpPathSingleFile2152026/09/23 13:29:16 WARN Rate limiter backed off name=server-test rate=52162026/09/23 13:29:16 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58644217--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)218=== CONT TestDumpPathMatchesNix219=== RUN TestSetClientTLS/rejects_connection_without_client_cert220=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert221=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA222=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA223=== RUN TestSetClientTLS/preserves_debug_logging_transport224=== PAUSE TestSetClientTLS/preserves_debug_logging_transport225=== CONT TestFilterOversizedClosures226=== RUN TestFilterOversizedClosures/no_limit_keeps_everything227=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything228=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped229=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== RUN TestFilterOversizedClosures/all_closures_skipped231=== PAUSE TestFilterOversizedClosures/all_closures_skipped232=== CONT TestPartSizeForNAR233=== RUN TestPartSizeForNAR/zero_stays_at_minimum234=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum235=== RUN TestPartSizeForNAR/small_stays_at_minimum236=== PAUSE TestPartSizeForNAR/small_stays_at_minimum237=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum238=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum239=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts240=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts241=== RUN TestPartSizeForNAR/1_TiB242=== PAUSE TestPartSizeForNAR/1_TiB243=== RUN TestPartSizeForNAR/5_TiB_S3_max_object244=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object245=== RUN TestPartSizeForNAR/capped_at_5_GiB246=== PAUSE TestPartSizeForNAR/capped_at_5_GiB247=== CONT TestUploadMultipart_PartsInParallel248--- PASS: TestScriptTokenBadJSON (0.01s)249=== CONT TestStreamPushBatchesUnderLoad250--- PASS: TestScriptTokenEmptyToken (0.01s)251=== CONT TestCaseHackSuffix252--- PASS: TestStreamPushRequestLine (0.02s)253=== CONT TestStreamPushGivesUpOnDeadServer2542026/09/23 13:29:16 ERROR Upload failed error="connection refused" count=202552026/09/23 13:29:16 ERROR Server seems unavailable, giving up on batch untried=17256--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)257=== CONT TestStreamPushReportsEveryPath258--- PASS: TestStreamPushReportsEveryPath (0.00s)259=== CONT TestStreamPushIsolatesFailures2602026/09/23 13:29:16 ERROR Upload failed error="bad path" count=3261--- PASS: TestStreamPushIsolatesFailures (0.00s)262=== CONT TestRegisterUploadedObjectReusesConnections263--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)264=== CONT TestShellSplitErrors265--- PASS: TestShellSplitErrors (0.00s)266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/missing_ca_file268--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)269=== CONT TestSetClientTLSErrors/invalid_ca_file270=== CONT TestSetClientTLSErrors/missing_key_file271=== CONT TestRateLimiterFeedback/429_enables_limiter272=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter273--- PASS: TestSetClientTLSErrors (0.00s)274 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)275 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)276 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)277 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)2782026/09/23 13:29:16 WARN Rate limiter enabled after throttle name=server-test rate=52792026/09/23 13:29:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:58719280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2812026/09/23 13:29:16 WARN Rate limiter backed off name=server-test rate=5282=== CONT TestRateLimiterFeedback/503_enables_limiter283=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2842026/09/23 13:29:16 WARN Rate limiter enabled after throttle name=server-test rate=52852026/09/23 13:29:16 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:58725286=== CONT TestPathInfoCACompatibility/null_ca_field287=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method288=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths289--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)290 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)291 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)292=== CONT TestParsePathInfoJSON/Nix_format293=== CONT TestPathInfoCACompatibility/new_structured_format_-_text294=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== CONT TestPathInfoCACompatibility/old_string_format_-_text296--- PASS: TestPathInfoCACompatibility (0.00s)297 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)299 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)300 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)301 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)302=== 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_with_sha512314=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI315=== 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_with_sha512 (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)320 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)321=== CONT TestGetStorePathHash/valid_store_path322=== CONT TestUploadMultipart_SupersededByPeer/exists3232026/09/23 13:29:16 WARN Rate limiter backed off name=server-test rate=5324--- PASS: TestRateLimiterFeedback (0.00s)325 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)326 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)327 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)328 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)329=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error330=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error331=== CONT TestGetStorePathHash/basename_without_hyphen_should_error332--- PASS: TestGetStorePathHash (0.00s)333 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)334 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)335 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)336 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)337=== CONT TestUploadMultipart_SupersededByPeer/missing338=== CONT TestEncodeNixBase32/test_string_hash339=== CONT TestEncodeNixBase32/empty_input340--- PASS: TestEncodeNixBase32 (0.00s)341 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)342 --- PASS: TestEncodeNixBase32/empty_input (0.00s)343=== CONT TestConvertHashToNix32/SRI_format_to_Nix32344=== CONT TestConvertHashToNix32/invalid_format345=== CONT TestConvertHashToNix32/already_Nix32_format346--- PASS: TestConvertHashToNix32 (0.00s)347 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)348 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)349 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)350=== CONT TestSetClientTLS/rejects_connection_without_client_cert351--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)352 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)353 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)354=== CONT TestSetClientTLS/preserves_debug_logging_transport355=== CONT TestFilterOversizedClosures/no_limit_keeps_everything356=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA357=== CONT TestPartSizeForNAR/zero_stays_at_minimum358=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3592026/09/23 13:29:16 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=2000360=== CONT TestFilterOversizedClosures/all_closures_skipped3612026/09/23 13:29:16 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=50362--- PASS: TestFilterOversizedClosures (0.00s)363 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)364 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)365 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)366=== CONT TestPartSizeForNAR/1_TiB367=== CONT TestPartSizeForNAR/capped_at_5_GiB368=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum369=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts370=== CONT TestPartSizeForNAR/small_stays_at_minimum371--- PASS: TestDumpPathWriterError (0.04s)372=== CONT TestPartSizeForNAR/5_TiB_S3_max_object373--- PASS: TestPartSizeForNAR (0.00s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)376 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)377 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)381--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)3822026/09/23 13:29:16 http: TLS handshake error from 127.0.0.1:58731: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.11s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".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-62986-3424006005/postgres461406784/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-62986-3424006005/postgres461406784/data -l logfile start421422/nix/var/nix/builds/nix-62986-3424006005/postgres461406784:5432 - no response4232026-09-23 13:29:18.603 UTC [63033] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-23 13:29:18.603 UTC [63033] LOG: listening on Unix socket "/nix/var/nix/builds/nix-62986-3424006005/postgres461406784/.s.PGSQL.5432"4252026-09-23 13:29:18.605 UTC [63040] LOG: database system was shut down at 2026-09-23 13:29:18 UTC4262026-09-23 13:29:18.606 UTC [63033] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-62986-3424006005/postgres461406784:5432 - accepting connections428=== RUN TestService_AuthMiddleware429=== PAUSE TestService_AuthMiddleware430=== RUN TestService_AuthMiddleware_MTLSProxyHeader431=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader432=== RUN TestService_AuthMiddleware_MTLSBoundSubjects433=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects434=== RUN TestService_ReadAuthMiddleware435=== PAUSE TestService_ReadAuthMiddleware436=== RUN TestService_AuthMiddleware_OIDC437=== PAUSE TestService_AuthMiddleware_OIDC438=== RUN TestService_RequireScope_OIDC439=== PAUSE TestService_RequireScope_OIDC440=== RUN TestService_ReadScope_PublicByDefault441=== PAUSE TestService_ReadScope_PublicByDefault442=== RUN TestCacheConfigHandler443=== PAUSE TestCacheConfigHandler444=== RUN TestCacheStatsHandler445=== PAUSE TestCacheStatsHandler446=== RUN TestClientCADerivations447=== PAUSE TestClientCADerivations448=== RUN TestClientErrorHandling449=== PAUSE TestClientErrorHandling450=== RUN TestClientIntegration451=== PAUSE TestClientIntegration452=== RUN TestClientMultipleUploads453=== PAUSE TestClientMultipleUploads454=== RUN TestClientWithDependencies455=== PAUSE TestClientWithDependencies456=== RUN TestClientSharedPathCommittedMidPush457=== PAUSE TestClientSharedPathCommittedMidPush458=== RUN TestPinProtectsFromGC459=== PAUSE TestPinProtectsFromGC460=== RUN TestClientPushesUseOnePush461=== PAUSE TestClientPushesUseOnePush462=== RUN TestClientFallsBackToClosures463=== PAUSE TestClientFallsBackToClosures464=== RUN TestResolveDBConnectionString465=== PAUSE TestResolveDBConnectionString466=== RUN TestLeadElectsOneAndHandsOver467=== PAUSE TestLeadElectsOneAndHandsOver468=== RUN TestLeadIncumbentWinsAfterRestart4692026-09-23 13:29:18.936 UTC [63078] ERROR: relation "goose_db_version" does not exist at character 364702026-09-23 13:29:18.936 UTC [63078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4712026/09/23 13:29:18 OK 20241026095416_initial_model.sql (3.19ms)4722026/09/23 13:29:18 OK 20251210153512_drop_unused_gin_index.sql (374.63µs)4732026/09/23 13:29:18 OK 20251218171726_add_pins.sql (733.88µs)4742026/09/23 13:29:18 OK 20260628120000_add_object_size_and_stats.sql (840.88µs)4752026/09/23 13:29:18 OK 20260905000000_add_claims.sql (1.14ms)4762026/09/23 13:29:18 OK 20260920000000_drop_claims.sql (587.33µs)4772026/09/23 13:29:18 OK 20260923120000_add_pushes.sql (443.5µs)4782026/09/23 13:29:18 goose: successfully migrated database to version: 202609231200004792026/09/23 13:29:18 OK 1_commit_pending_closure.sql (779.92µs)4802026/09/23 13:29:18 OK 2_object_stats_trigger.sql (190.75µs)4812026/09/23 13:29:18 OK 3_commit_push.sql (174µs)4822026/09/23 13:29:18 goose: up to current file version: 34832026/09/23 13:29:19 INFO lead: acquired remote=192.0.2.1:12344842026/09/23 13:29:19 INFO lead: released remote=192.0.2.1:12344852026/09/23 13:29:19 INFO lead: acquired remote=192.0.2.1:12344862026/09/23 13:29:19 INFO lead: released remote=192.0.2.1:1234487--- PASS: TestLeadIncumbentWinsAfterRestart (0.86s)488=== RUN TestLeadEndsOnShutdown489=== PAUSE TestLeadEndsOnShutdown490=== RUN TestGCAdvisoryLockBlocksConcurrentRun4912026-09-23 13:29:19.709 UTC [63100] ERROR: relation "goose_db_version" does not exist at character 364922026-09-23 13:29:19.709 UTC [63100] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4932026/09/23 13:29:19 OK 20241026095416_initial_model.sql (3.05ms)4942026/09/23 13:29:19 OK 20251210153512_drop_unused_gin_index.sql (449.71µs)4952026/09/23 13:29:19 OK 20251218171726_add_pins.sql (757.92µs)4962026/09/23 13:29:19 OK 20260628120000_add_object_size_and_stats.sql (818.17µs)4972026/09/23 13:29:19 OK 20260905000000_add_claims.sql (876µs)4982026/09/23 13:29:19 OK 20260920000000_drop_claims.sql (599.88µs)4992026/09/23 13:29:19 OK 20260923120000_add_pushes.sql (414.5µs)5002026/09/23 13:29:19 goose: successfully migrated database to version: 202609231200005012026/09/23 13:29:19 OK 1_commit_pending_closure.sql (827.08µs)5022026/09/23 13:29:19 OK 2_object_stats_trigger.sql (218.17µs)5032026/09/23 13:29:19 OK 3_commit_push.sql (199.83µs)5042026/09/23 13:29:19 goose: up to current file version: 3505--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestGCTaskStore_StartNew511=== PAUSE TestGCTaskStore_StartNew512=== RUN TestGCTaskStore_DeduplicateSameParams513=== PAUSE TestGCTaskStore_DeduplicateSameParams514=== RUN TestGCTaskStore_ConflictDifferentParams515=== PAUSE TestGCTaskStore_ConflictDifferentParams516=== RUN TestGCTaskStore_GetEmpty517=== PAUSE TestGCTaskStore_GetEmpty518=== RUN TestGCTaskStore_GetReturnsLatest519=== PAUSE TestGCTaskStore_GetReturnsLatest520=== RUN TestGCTaskStore_CompletedAllowsNewTask521=== PAUSE TestGCTaskStore_CompletedAllowsNewTask522=== RUN TestGCTaskStore_PhaseUpdates523=== PAUSE TestGCTaskStore_PhaseUpdates524=== RUN TestGCTaskStore_Fail525=== PAUSE TestGCTaskStore_Fail526=== RUN TestGracefulShutdownDrainsInflight527=== PAUSE TestGracefulShutdownDrainsInflight528=== RUN TestService_healthCheckHandler529=== PAUSE TestService_healthCheckHandler530=== RUN TestService_readinessHandler531=== PAUSE TestService_readinessHandler532=== RUN TestGenerateLandingPage533=== PAUSE TestGenerateLandingPage534=== RUN TestCacheConfigHandlerMaxNarSize535=== PAUSE TestCacheConfigHandlerMaxNarSize536=== RUN TestCreatePendingClosureRejectsOversizedNAR537=== PAUSE TestCreatePendingClosureRejectsOversizedNAR538=== RUN TestNARDeduplicationMetadataUploadBug539=== PAUSE TestNARDeduplicationMetadataUploadBug540=== RUN TestMetricsInventory541=== PAUSE TestMetricsInventory542=== RUN TestService_NativeMTLS543=== PAUSE TestService_NativeMTLS544=== RUN TestServerTLSConfig545=== PAUSE TestServerTLSConfig546=== RUN TestMultipartCleanup547=== PAUSE TestMultipartCleanup548=== RUN TestObjectStatsTrigger549=== PAUSE TestObjectStatsTrigger550=== RUN TestOrphanedObjectsGC551=== PAUSE TestOrphanedObjectsGC552=== RUN TestOrphanedObjectsGCStressTest553=== PAUSE TestOrphanedObjectsGCStressTest554=== RUN TestResurrectedObjectNotDeleted555=== PAUSE TestResurrectedObjectNotDeleted556=== RUN TestCreatePin_ReservedPins557=== PAUSE TestCreatePin_ReservedPins558=== RUN TestParseSingleRange559=== PAUSE TestParseSingleRange560=== RUN TestProxyHeadersOnlyTrustedOnSocket561=== PAUSE TestProxyHeadersOnlyTrustedOnSocket562=== RUN TestIsValidCachePath563=== PAUSE TestIsValidCachePath564=== RUN TestReadProxyNarinfo565=== PAUSE TestReadProxyNarinfo566=== RUN TestReadProxyNarinfoAlreadyDecompressed567=== PAUSE TestReadProxyNarinfoAlreadyDecompressed568=== RUN TestReadProxyNarStreaming569=== PAUSE TestReadProxyNarStreaming570=== RUN TestReadProxy404571=== PAUSE TestReadProxy404572=== RUN TestReadProxyInvalidPath573=== PAUSE TestReadProxyInvalidPath574=== RUN TestReadProxyHead575=== PAUSE TestReadProxyHead576=== RUN TestReadProxyConditionalGet577=== PAUSE TestReadProxyConditionalGet578=== RUN TestReadProxyRootRedirectsToIndexHTML579=== PAUSE TestReadProxyRootRedirectsToIndexHTML580=== RUN TestReadProxyDisabled581=== PAUSE TestReadProxyDisabled582=== RUN TestReadRedirectNar583=== PAUSE TestReadRedirectNar584=== RUN TestReadRedirectKeepsNarinfoProxied585=== PAUSE TestReadRedirectKeepsNarinfoProxied586=== RUN TestReadProxyRangeRequest587=== PAUSE TestReadProxyRangeRequest588=== RUN TestReadRedirectUsesPublicS3URL589=== PAUSE TestReadRedirectUsesPublicS3URL590=== RUN TestPush_OverlappingRootsStoreOneRowPerKey591=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey592=== RUN TestPush_CompleteCommitsEveryRoot593=== PAUSE TestPush_CompleteCommitsEveryRoot594=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected595=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected596=== RUN TestPush_RejectsBadRequests597=== PAUSE TestPush_RejectsBadRequests598=== RUN TestPush_SignsNarinfosOfItsPendingObjects599=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects600=== RUN TestRedundantMultipartUpload601=== PAUSE TestRedundantMultipartUpload602=== RUN TestCompleteMultipartUpload_ErrorButObjectExists603=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists604=== RUN TestCompletedNarNotReofferedAcrossClosures605=== PAUSE TestCompletedNarNotReofferedAcrossClosures606=== RUN TestPresignedUploadRegisteredBeforeCommit607=== PAUSE TestPresignedUploadRegisteredBeforeCommit608=== RUN TestService_Rustfstest609=== PAUSE TestService_Rustfstest610=== RUN TestParseSize611=== PAUSE TestParseSize612=== RUN TestSkippedUploadsHandler613=== PAUSE TestSkippedUploadsHandler614=== RUN TestSystemdListenerNotActivated615--- PASS: TestSystemdListenerNotActivated (0.00s)616=== RUN TestWatchdogBeatsWhenHealthy617--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)618=== RUN TestWatchdogSkipsWhenUnhealthy6192026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6202026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:29:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:29:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"629--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)630=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle631=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== RUN TestProxyWriteTimeout633=== PAUSE TestProxyWriteTimeout634=== RUN TestIsValidUploadKey635=== PAUSE TestIsValidUploadKey636=== RUN TestUploadHandlersRejectInvalidKeys637=== PAUSE TestUploadHandlersRejectInvalidKeys638=== RUN TestUploadHandlersRejectOversizedBody639=== PAUSE TestUploadHandlersRejectOversizedBody640=== RUN TestService_cleanupPendingClosuresHandler641=== PAUSE TestService_cleanupPendingClosuresHandler642=== RUN TestService_createPendingClosureHandler643=== PAUSE TestService_createPendingClosureHandler644=== RUN TestService_verifyS3Integrity645=== PAUSE TestService_verifyS3Integrity646=== RUN TestCompleteMultipartUnregistered647=== PAUSE TestCompleteMultipartUnregistered648=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT649=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT650=== CONT TestService_AuthMiddleware651=== CONT TestReadProxyNarStreaming652=== CONT TestCompleteMultipartUpload_ErrorButObjectExists653=== CONT TestIsValidUploadKey654=== RUN TestIsValidUploadKey/narinfo655=== CONT TestReadProxyRangeRequest656=== CONT TestService_createPendingClosureHandler657=== CONT TestService_cleanupPendingClosuresHandler658=== PAUSE TestIsValidUploadKey/narinfo659=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT660=== CONT TestCompleteMultipartUnregistered661=== CONT TestService_verifyS3Integrity662=== RUN TestIsValidUploadKey/nar_zst663=== PAUSE TestIsValidUploadKey/nar_zst664=== RUN TestIsValidUploadKey/nar_xz665=== PAUSE TestIsValidUploadKey/nar_xz666=== RUN TestIsValidUploadKey/nar_plain667=== PAUSE TestIsValidUploadKey/nar_plain668=== RUN TestIsValidUploadKey/listing669=== PAUSE TestIsValidUploadKey/listing670=== RUN TestIsValidUploadKey/build_log671=== PAUSE TestIsValidUploadKey/build_log672=== RUN TestIsValidUploadKey/build_log_home-manager_file673=== PAUSE TestIsValidUploadKey/build_log_home-manager_file674=== RUN TestIsValidUploadKey/build_log_plus_in_name675=== PAUSE TestIsValidUploadKey/build_log_plus_in_name676=== RUN TestIsValidUploadKey/build_log_question_mark677=== PAUSE TestIsValidUploadKey/build_log_question_mark678=== RUN TestIsValidUploadKey/build_log_equals679=== PAUSE TestIsValidUploadKey/build_log_equals680=== RUN TestIsValidUploadKey/realisation681=== PAUSE TestIsValidUploadKey/realisation682=== RUN TestIsValidUploadKey/realisation_plus_in_output683=== PAUSE TestIsValidUploadKey/realisation_plus_in_output684=== RUN TestIsValidUploadKey/nix-cache-info685=== PAUSE TestIsValidUploadKey/nix-cache-info686=== RUN TestIsValidUploadKey/index.html687=== PAUSE TestIsValidUploadKey/index.html688=== RUN TestIsValidUploadKey/narinfo_key,_nar_type689=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type690=== RUN TestIsValidUploadKey/nar_key,_narinfo_type691=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type692=== RUN TestIsValidUploadKey/listing_key,_narinfo_type693=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type694=== RUN TestIsValidUploadKey/traversal695=== PAUSE TestIsValidUploadKey/traversal696=== RUN TestIsValidUploadKey/traversal_nar697=== PAUSE TestIsValidUploadKey/traversal_nar698=== RUN TestIsValidUploadKey/absolute699=== PAUSE TestIsValidUploadKey/absolute700=== RUN TestIsValidUploadKey/empty_key701=== PAUSE TestIsValidUploadKey/empty_key702=== RUN TestIsValidUploadKey/unknown_type703=== PAUSE TestIsValidUploadKey/unknown_type704=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected7052026-09-23 13:29:20.316 UTC [63126] ERROR: relation "goose_db_version" does not exist at character 367062026-09-23 13:29:20.316 UTC [63126] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026-09-23 13:29:20.326 UTC [63127] ERROR: relation "goose_db_version" does not exist at character 367082026-09-23 13:29:20.326 UTC [63127] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026-09-23 13:29:20.327 UTC [63128] ERROR: relation "goose_db_version" does not exist at character 367102026-09-23 13:29:20.327 UTC [63128] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7112026-09-23 13:29:20.328 UTC [63129] ERROR: relation "goose_db_version" does not exist at character 367122026-09-23 13:29:20.328 UTC [63129] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-23 13:29:20.329 UTC [63130] ERROR: relation "goose_db_version" does not exist at character 367142026-09-23 13:29:20.329 UTC [63130] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-09-23 13:29:20.330 UTC [63133] ERROR: relation "goose_db_version" does not exist at character 367162026-09-23 13:29:20.330 UTC [63133] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026-09-23 13:29:20.330 UTC [63135] ERROR: relation "goose_db_version" does not exist at character 367182026-09-23 13:29:20.330 UTC [63135] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026-09-23 13:29:20.331 UTC [63132] ERROR: relation "goose_db_version" does not exist at character 367202026-09-23 13:29:20.331 UTC [63132] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7212026-09-23 13:29:20.331 UTC [63131] ERROR: relation "goose_db_version" does not exist at character 367222026-09-23 13:29:20.331 UTC [63131] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026-09-23 13:29:20.332 UTC [63134] ERROR: relation "goose_db_version" does not exist at character 367242026-09-23 13:29:20.332 UTC [63134] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026/09/23 13:29:20 OK 20241026095416_initial_model.sql (9.49ms)7262026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (882.42µs)7272026/09/23 13:29:20 OK 20241026095416_initial_model.sql (5.6ms)7282026/09/23 13:29:20 OK 20251218171726_add_pins.sql (2.04ms)7292026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (895.08µs)7302026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.71ms)7312026/09/23 13:29:20 OK 20251218171726_add_pins.sql (2.41ms)7322026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7.87ms)7332026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7.3ms)7342026/09/23 13:29:20 OK 20260905000000_add_claims.sql (2.56ms)7352026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (568.75µs)7362026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (770.58µs)7372026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (2.08ms)7382026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7ms)7392026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (1.31ms)7402026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7.47ms)7412026/09/23 13:29:20 OK 20241026095416_initial_model.sql (8.62ms)7422026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (695.5µs)7432026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (898µs)7442026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200007452026/09/23 13:29:20 OK 20251218171726_add_pins.sql (1.6ms)7462026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (680.54µs)7472026/09/23 13:29:20 OK 20251218171726_add_pins.sql (2.3ms)7482026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (680.04µs)7492026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7.39ms)7502026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7.96ms)7512026/09/23 13:29:20 OK 20260905000000_add_claims.sql (2.46ms)7522026/09/23 13:29:20 OK 20241026095416_initial_model.sql (7.57ms)7532026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (968.21µs)7542026/09/23 13:29:20 OK 1_commit_pending_closure.sql (1.6ms)7552026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.49ms)7562026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (667.38µs)7572026/09/23 13:29:20 OK 20251218171726_add_pins.sql (2.22ms)7582026/09/23 13:29:20 OK 20251218171726_add_pins.sql (1.83ms)7592026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.97ms)7602026/09/23 13:29:20 OK 20251218171726_add_pins.sql (1.71ms)7612026/09/23 13:29:20 OK 20251210153512_drop_unused_gin_index.sql (630.88µs)7622026/09/23 13:29:20 OK 2_object_stats_trigger.sql (542.42µs)7632026/09/23 13:29:20 OK 3_commit_push.sql (417.58µs)7642026/09/23 13:29:20 goose: up to current file version: 37652026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (1.44ms)7662026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.62ms)7672026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.67ms)7682026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (931.08µs)7692026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200007702026/09/23 13:29:20 OK 20251218171726_add_pins.sql (1.9ms)7712026/09/23 13:29:20 OK 20251218171726_add_pins.sql (1.79ms)7722026/09/23 13:29:20 OK 20260905000000_add_claims.sql (2.26ms)7732026/09/23 13:29:20 OK 20251218171726_add_pins.sql (2.41ms)7742026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (2.16ms)7752026/09/23 13:29:20 OK 20260905000000_add_claims.sql (2.5ms)7762026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.18ms)7772026/09/23 13:29:20 OK 20260905000000_add_claims.sql (1.35ms)7782026/09/23 13:29:20 OK 20260905000000_add_claims.sql (1.38ms)7792026/09/23 13:29:20 OK 1_commit_pending_closure.sql (1.44ms)7802026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (1.42ms)7812026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (1.84ms)7822026/09/23 13:29:20 OK 2_object_stats_trigger.sql (593.54µs)7832026/09/23 13:29:20 OK 3_commit_push.sql (183.13µs)7842026/09/23 13:29:20 goose: up to current file version: 37852026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (8.07ms)7862026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (7.65ms)7872026/09/23 13:29:20 OK 20260628120000_add_object_size_and_stats.sql (8.71ms)7882026/09/23 13:29:20 OK 20260905000000_add_claims.sql (8.67ms)7892026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (44.18ms)7902026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (43.95ms)7912026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200007922026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (36.76ms)7932026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200007942026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (37.04ms)7952026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200007962026/09/23 13:29:20 OK 1_commit_pending_closure.sql (957.96µs)7972026/09/23 13:29:20 OK 1_commit_pending_closure.sql (1.16ms)7982026/09/23 13:29:20 OK 1_commit_pending_closure.sql (995.67µs)7992026/09/23 13:29:20 OK 2_object_stats_trigger.sql (318.58µs)8002026/09/23 13:29:20 OK 2_object_stats_trigger.sql (314.54µs)8012026/09/23 13:29:20 OK 2_object_stats_trigger.sql (218.46µs)8022026/09/23 13:29:20 OK 3_commit_push.sql (184.04µs)8032026/09/23 13:29:20 goose: up to current file version: 38042026/09/23 13:29:20 OK 3_commit_push.sql (182.38µs)8052026/09/23 13:29:20 goose: up to current file version: 38062026/09/23 13:29:20 OK 3_commit_push.sql (193.42µs)8072026/09/23 13:29:20 goose: up to current file version: 38082026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (44.22ms)8092026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (7.99ms)8102026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200008112026/09/23 13:29:20 OK 20260905000000_add_claims.sql (52.4ms)8122026/09/23 13:29:20 OK 20260905000000_add_claims.sql (51.79ms)8132026/09/23 13:29:20 OK 20260905000000_add_claims.sql (44.9ms)8142026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (628.21µs)8152026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200008162026/09/23 13:29:20 OK 1_commit_pending_closure.sql (835.71µs)8172026/09/23 13:29:20 OK 2_object_stats_trigger.sql (306.13µs)8182026/09/23 13:29:20 OK 1_commit_pending_closure.sql (823.5µs)8192026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (1.3ms)8202026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (1.11ms)8212026/09/23 13:29:20 OK 2_object_stats_trigger.sql (243.33µs)8222026/09/23 13:29:20 OK 3_commit_push.sql (394.17µs)8232026/09/23 13:29:20 goose: up to current file version: 38242026/09/23 13:29:20 OK 3_commit_push.sql (207.71µs)8252026/09/23 13:29:20 goose: up to current file version: 38262026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (6.54ms)8272026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200008282026/09/23 13:29:20 OK 1_commit_pending_closure.sql (684µs)8292026/09/23 13:29:20 OK 2_object_stats_trigger.sql (200.96µs)8302026/09/23 13:29:20 OK 3_commit_push.sql (169.29µs)8312026/09/23 13:29:20 goose: up to current file version: 38322026/09/23 13:29:20 OK 20260920000000_drop_claims.sql (10ms)8332026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (9.02ms)8342026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200008352026/09/23 13:29:20 OK 1_commit_pending_closure.sql (707.42µs)8362026/09/23 13:29:20 OK 2_object_stats_trigger.sql (186.67µs)8372026/09/23 13:29:20 OK 3_commit_push.sql (180.88µs)8382026/09/23 13:29:20 goose: up to current file version: 38392026/09/23 13:29:20 OK 20260923120000_add_pushes.sql (6.3ms)8402026/09/23 13:29:20 goose: successfully migrated database to version: 202609231200008412026/09/23 13:29:20 OK 1_commit_pending_closure.sql (811.29µs)8422026/09/23 13:29:20 OK 2_object_stats_trigger.sql (188.25µs)8432026/09/23 13:29:20 OK 3_commit_push.sql (165.96µs)8442026/09/23 13:29:20 goose: up to current file version: 3845--- PASS: TestReadProxyNarStreaming (0.44s)846=== CONT TestRedundantMultipartUpload8472026/09/23 13:29:20 INFO Received cleanup request method=DELETE path=/api/pending_closures8482026/09/23 13:29:20 INFO Aborted multipart uploads count=08492026/09/23 13:29:20 INFO Received uploads request method=POST path=/api/pending_closures8502026/09/23 13:29:20 INFO Received cleanup request method=DELETE path=/api/pending_closures8512026/09/23 13:29:20 INFO Aborted multipart uploads count=18522026/09/23 13:29:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8532026-09-23 13:29:20.643 UTC [63127] ERROR: Closure does not exist: id=18542026-09-23 13:29:20.643 UTC [63127] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8552026-09-23 13:29:20.643 UTC [63127] STATEMENT: -- name: CommitPendingClosure :exec856 SELECT commit_pending_closure($1::bigint)857 858--- PASS: TestService_cleanupPendingClosuresHandler (0.61s)859=== CONT TestPush_SignsNarinfosOfItsPendingObjects8602026/09/23 13:29:20 INFO Received push request method=POST path=/api/pushes8612026/09/23 13:29:20 INFO Received complete push request method=POST path=/api/pushes/1/complete8622026/09/23 13:29:20 INFO Received push request method=POST path=/api/pushes8632026/09/23 13:29:20 INFO Received complete push request method=POST path=/api/pushes/2/complete8642026-09-23 13:29:20.895 UTC [63140] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo8652026-09-23 13:29:20.895 UTC [63140] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE8662026-09-23 13:29:20.895 UTC [63140] STATEMENT: -- name: CommitPush :exec867 SELECT commit_push($1::bigint)868 869--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.86s)870=== CONT TestPush_RejectsBadRequests871--- PASS: TestReadProxyRangeRequest (0.94s)872=== CONT TestProxyWriteTimeout873=== RUN TestProxyWriteTimeout/narinfo874=== PAUSE TestProxyWriteTimeout/narinfo875=== RUN TestProxyWriteTimeout/1_GiB_nar876=== PAUSE TestProxyWriteTimeout/1_GiB_nar877=== RUN TestProxyWriteTimeout/10_GiB_nar878=== PAUSE TestProxyWriteTimeout/10_GiB_nar879=== RUN TestProxyWriteTimeout/unknown_size880=== PAUSE TestProxyWriteTimeout/unknown_size881=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8822026/09/23 13:29:21 INFO Received uploads request method=POST path=/api/pending_closures8832026-09-23 13:29:21.273 UTC [63145] ERROR: relation "goose_db_version" does not exist at character 368842026-09-23 13:29:21.273 UTC [63145] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/09/23 13:29:21 INFO Received uploads request method=POST path=/api/pending_closures886--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.34s)887=== CONT TestSkippedUploadsHandler8882026/09/23 13:29:21 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000889--- PASS: TestSkippedUploadsHandler (0.00s)890=== CONT TestParseSize891--- PASS: TestParseSize (0.00s)892=== CONT TestService_Rustfstest8932026/09/23 13:29:21 OK 20241026095416_initial_model.sql (97.77ms)8942026/09/23 13:29:21 OK 20251210153512_drop_unused_gin_index.sql (8.44ms)8952026/09/23 13:29:21 OK 20251218171726_add_pins.sql (25.69ms)8962026-09-23 13:29:21.449 UTC [63148] ERROR: relation "goose_db_version" does not exist at character 368972026-09-23 13:29:21.449 UTC [63148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026/09/23 13:29:21 OK 20260628120000_add_object_size_and_stats.sql (14.49ms)8992026/09/23 13:29:21 OK 20260905000000_add_claims.sql (30.28ms)9002026/09/23 13:29:21 OK 20260920000000_drop_claims.sql (16.43ms)9012026/09/23 13:29:21 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"902--- PASS: TestService_AuthMiddleware (1.49s)903=== CONT TestPresignedUploadRegisteredBeforeCommit9042026/09/23 13:29:21 OK 20260923120000_add_pushes.sql (69.67ms)9052026/09/23 13:29:21 goose: successfully migrated database to version: 202609231200009062026/09/23 13:29:21 OK 1_commit_pending_closure.sql (2.31ms)9072026/09/23 13:29:21 OK 2_object_stats_trigger.sql (505.71µs)9082026/09/23 13:29:21 OK 3_commit_push.sql (376.79µs)9092026/09/23 13:29:21 goose: up to current file version: 39102026/09/23 13:29:21 OK 20241026095416_initial_model.sql (112.77ms)9112026/09/23 13:29:21 OK 20251210153512_drop_unused_gin_index.sql (6.77ms)9122026/09/23 13:29:21 OK 20251218171726_add_pins.sql (10.6ms)9132026/09/23 13:29:21 OK 20260628120000_add_object_size_and_stats.sql (32.8ms)9142026/09/23 13:29:21 OK 20260905000000_add_claims.sql (38.93ms)9152026/09/23 13:29:21 OK 20260920000000_drop_claims.sql (26.32ms)9162026/09/23 13:29:21 OK 20260923120000_add_pushes.sql (9.04ms)9172026/09/23 13:29:21 goose: successfully migrated database to version: 202609231200009182026-09-23 13:29:21.727 UTC [63151] ERROR: relation "goose_db_version" does not exist at character 369192026-09-23 13:29:21.727 UTC [63151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026/09/23 13:29:21 OK 1_commit_pending_closure.sql (2.97ms)9212026/09/23 13:29:21 OK 2_object_stats_trigger.sql (495.54µs)9222026/09/23 13:29:21 OK 3_commit_push.sql (420.67µs)9232026/09/23 13:29:21 goose: up to current file version: 39242026/09/23 13:29:21 INFO Received uploads request method=POST path=/api/pending_closures9252026/09/23 13:29:21 INFO Received uploads request method=POST path=/api/pending_closures9262026/09/23 13:29:21 INFO Received uploads request method=POST path=/api/pending_closures9272026-09-23 13:29:21.842 UTC [63152] ERROR: relation "goose_db_version" does not exist at character 369282026-09-23 13:29:21.842 UTC [63152] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026/09/23 13:29:21 OK 20241026095416_initial_model.sql (110.34ms)9302026/09/23 13:29:21 OK 20251210153512_drop_unused_gin_index.sql (15ms)9312026/09/23 13:29:21 OK 20251218171726_add_pins.sql (29.24ms)9322026/09/23 13:29:21 OK 20260628120000_add_object_size_and_stats.sql (25.61ms)9332026/09/23 13:29:21 INFO Received uploads request method=POST path=/api/pending_closures9342026/09/23 13:29:22 OK 20260905000000_add_claims.sql (65.31ms)9352026/09/23 13:29:22 OK 20241026095416_initial_model.sql (194.08ms)9362026/09/23 13:29:22 OK 20260920000000_drop_claims.sql (51.94ms)9372026/09/23 13:29:22 OK 20251210153512_drop_unused_gin_index.sql (7.82ms)9382026/09/23 13:29:22 OK 20260923120000_add_pushes.sql (15.12ms)9392026/09/23 13:29:22 goose: successfully migrated database to version: 202609231200009402026/09/23 13:29:22 OK 1_commit_pending_closure.sql (3.27ms)9412026/09/23 13:29:22 OK 2_object_stats_trigger.sql (936.17µs)9422026/09/23 13:29:22 OK 3_commit_push.sql (603.38µs)9432026/09/23 13:29:22 goose: up to current file version: 39442026/09/23 13:29:22 OK 20251218171726_add_pins.sql (25.06ms)9452026/09/23 13:29:22 OK 20260628120000_add_object_size_and_stats.sql (21.42ms)9462026/09/23 13:29:22 OK 20260905000000_add_claims.sql (81.08ms)9472026/09/23 13:29:22 OK 20260920000000_drop_claims.sql (26.96ms)9482026/09/23 13:29:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9492026/09/23 13:29:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWVjZmI4MmEtZDFiMi00YTFmLWJhNTctYzY5OGMzZmY1Mjg1LmI0ZTQ5YzQ2LTQ4YjMtNGE0Zi1iNDcxLTBhOGY2Njk4ZmU1ZngxNzkwMTcwMTYyMDI2MDE0MDAw9502026/09/23 13:29:22 OK 20260923120000_add_pushes.sql (16.7ms)9512026/09/23 13:29:22 goose: successfully migrated database to version: 202609231200009522026/09/23 13:29:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWVjZmI4MmEtZDFiMi00YTFmLWJhNTctYzY5OGMzZmY1Mjg1LmI0ZTQ5YzQ2LTQ4YjMtNGE0Zi1iNDcxLTBhOGY2Njk4ZmU1ZngxNzkwMTcwMTYyMDI2MDE0MDAw parts=1953--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.24s)954=== CONT TestCompletedNarNotReofferedAcrossClosures9552026/09/23 13:29:22 OK 1_commit_pending_closure.sql (2.44ms)9562026/09/23 13:29:22 OK 2_object_stats_trigger.sql (618.58µs)9572026/09/23 13:29:22 OK 3_commit_push.sql (395.54µs)9582026/09/23 13:29:22 goose: up to current file version: 39592026/09/23 13:29:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9602026/09/23 13:29:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst961--- PASS: TestCompleteMultipartUnregistered (2.28s)962=== CONT TestUploadHandlersRejectOversizedBody963=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure964=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure965=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart966=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart967=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts968=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts969=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9702026/09/23 13:29:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9712026/09/23 13:29:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWVjZmI4MmEtZDFiMi00YTFmLWJhNTctYzY5OGMzZmY1Mjg1LjU3ZmRlZTM2LWNhY2UtNDIwYi04ZTQxLTViMjBjYWE2MDAyZHgxNzkwMTcwMTYxMTMyMzI5MDAw parts=109722026/09/23 13:29:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9732026/09/23 13:29:22 INFO Completed upload id=19742026/09/23 13:29:22 INFO Received uploads request method=POST path=/api/pending_closures9752026/09/23 13:29:22 INFO Received uploads request method=POST path=/api/pending_closures9762026/09/23 13:29:22 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9772026/09/23 13:29:22 WARN Found objects in DB but missing from S3, will re-upload count=1978--- PASS: TestService_verifyS3Integrity (2.41s)979=== CONT TestReadRedirectKeepsNarinfoProxied9802026/09/23 13:29:22 INFO Received uploads request method=POST path=/api/pending_closures9812026/09/23 13:29:22 INFO Received uploads request method=POST path=/api/pending_closures9822026/09/23 13:29:22 INFO Received push request method=POST path=/api/pushes9832026/09/23 13:29:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9842026/09/23 13:29:22 INFO Signed narinfos id=1 count=1985--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.21s)986=== CONT TestReadRedirectNar987=== RUN TestPush_RejectsBadRequests/no_roots988=== PAUSE TestPush_RejectsBadRequests/no_roots989=== RUN TestPush_RejectsBadRequests/no_objects990=== PAUSE TestPush_RejectsBadRequests/no_objects991=== RUN TestPush_RejectsBadRequests/bad_root992=== PAUSE TestPush_RejectsBadRequests/bad_root993=== RUN TestPush_RejectsBadRequests/root_not_in_objects994=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects995=== CONT TestReadProxyDisabled9962026/09/23 13:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9972026/09/23 13:29:23 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWVjZmI4MmEtZDFiMi00YTFmLWJhNTctYzY5OGMzZmY1Mjg1LjVhOTM2NDZjLTVjYTktNGRmYi04NTA3LTg3ZTEzYzI2NDQ2MXgxNzkwMTcwMTYxNzc1MjYxMDAw parts=109982026/09/23 13:29:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9992026/09/23 13:29:23 INFO Completed upload id=110002026/09/23 13:29:23 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010012026/09/23 13:29:23 INFO Received uploads request method=POST path=/api/pending_closures10022026/09/23 13:29:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures10032026/09/23 13:29:23 INFO Aborted multipart uploads count=010042026/09/23 13:29:23 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=010052026/09/23 13:29:23 INFO Vacuumed table table=pending_closures10062026-09-23 13:29:23.196 UTC [63163] ERROR: relation "goose_db_version" does not exist at character 3610072026-09-23 13:29:23.196 UTC [63163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026/09/23 13:29:23 INFO Vacuumed table table=pending_objects10092026/09/23 13:29:23 INFO Vacuumed table table=multipart_uploads10102026-09-23 13:29:23.241 UTC [63165] ERROR: relation "goose_db_version" does not exist at character 3610112026-09-23 13:29:23.241 UTC [63165] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026/09/23 13:29:23 INFO Vacuumed table table=closures10132026/09/23 13:29:23 INFO Vacuumed table table=objects10142026/09/23 13:29:23 INFO Received uploads request method=POST path=/api/pending_closures10152026/09/23 13:29:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001016--- PASS: TestService_createPendingClosureHandler (3.32s)1017=== CONT TestReadProxyRootRedirectsToIndexHTML10182026/09/23 13:29:23 OK 20241026095416_initial_model.sql (113.21ms)10192026/09/23 13:29:23 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)10202026/09/23 13:29:23 OK 20251218171726_add_pins.sql (1.67ms)10212026/09/23 13:29:23 OK 20241026095416_initial_model.sql (82.72ms)10222026/09/23 13:29:23 OK 20260628120000_add_object_size_and_stats.sql (21.99ms)10232026/09/23 13:29:23 OK 20251210153512_drop_unused_gin_index.sql (7.86ms)10242026/09/23 13:29:23 OK 20251218171726_add_pins.sql (26.27ms)10252026/09/23 13:29:23 OK 20260905000000_add_claims.sql (39.98ms)10262026/09/23 13:29:23 OK 20260920000000_drop_claims.sql (9.23ms)10272026/09/23 13:29:23 OK 20260628120000_add_object_size_and_stats.sql (20.04ms)10282026/09/23 13:29:23 OK 20260923120000_add_pushes.sql (5.43ms)10292026/09/23 13:29:23 goose: successfully migrated database to version: 2026092312000010302026/09/23 13:29:23 OK 1_commit_pending_closure.sql (1.45ms)10312026/09/23 13:29:23 OK 2_object_stats_trigger.sql (314.75µs)10322026/09/23 13:29:23 OK 3_commit_push.sql (277µs)10332026/09/23 13:29:23 goose: up to current file version: 310342026/09/23 13:29:23 OK 20260905000000_add_claims.sql (9.04ms)10352026/09/23 13:29:23 OK 20260920000000_drop_claims.sql (36.41ms)10362026/09/23 13:29:23 OK 20260923120000_add_pushes.sql (15ms)10372026/09/23 13:29:23 goose: successfully migrated database to version: 2026092312000010382026/09/23 13:29:23 OK 1_commit_pending_closure.sql (1.39ms)10392026/09/23 13:29:23 OK 2_object_stats_trigger.sql (356.79µs)10402026/09/23 13:29:23 OK 3_commit_push.sql (282.04µs)10412026/09/23 13:29:23 goose: up to current file version: 310422026/09/23 13:29:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10432026/09/23 13:29:23 INFO Received uploads request method=POST path=/api/pending_closures10442026/09/23 13:29:23 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10452026/09/23 13:29:23 INFO Received uploads request method=POST path=/api/pending_closures1046--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.24s)1047=== CONT TestReadProxyConditionalGet1048--- PASS: TestService_Rustfstest (2.57s)1049=== CONT TestReadProxyHead10502026-09-23 13:29:24.018 UTC [63172] ERROR: relation "goose_db_version" does not exist at character 3610512026-09-23 13:29:24.018 UTC [63172] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10522026-09-23 13:29:24.018 UTC [63173] ERROR: relation "goose_db_version" does not exist at character 3610532026-09-23 13:29:24.018 UTC [63173] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10542026-09-23 13:29:24.019 UTC [63174] ERROR: relation "goose_db_version" does not exist at character 3610552026-09-23 13:29:24.019 UTC [63174] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10562026/09/23 13:29:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10572026/09/23 13:29:24 OK 20241026095416_initial_model.sql (60.56ms)10582026/09/23 13:29:24 OK 20241026095416_initial_model.sql (62.23ms)10592026/09/23 13:29:24 OK 20241026095416_initial_model.sql (62.56ms)10602026/09/23 13:29:24 OK 20251210153512_drop_unused_gin_index.sql (7.29ms)10612026/09/23 13:29:24 OK 20251210153512_drop_unused_gin_index.sql (6.01ms)10622026/09/23 13:29:24 OK 20251210153512_drop_unused_gin_index.sql (5.89ms)10632026/09/23 13:29:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWVjZmI4MmEtZDFiMi00YTFmLWJhNTctYzY5OGMzZmY1Mjg1LmI4OTQyZTljLWIxNzctNGQ1Zi05Zjk4LTk4N2M4NzZiOTc1YXgxNzkwMTcwMTYyNTc2ODAyMDAw parts=1210642026/09/23 13:29:24 OK 20251218171726_add_pins.sql (10.54ms)10652026/09/23 13:29:24 OK 20251218171726_add_pins.sql (11.09ms)1066--- PASS: TestRedundantMultipartUpload (3.66s)1067=== CONT TestReadProxyInvalidPath10682026/09/23 13:29:24 OK 20251218171726_add_pins.sql (20.38ms)10692026/09/23 13:29:24 OK 20260628120000_add_object_size_and_stats.sql (24.39ms)10702026/09/23 13:29:24 OK 20260628120000_add_object_size_and_stats.sql (15.78ms)10712026/09/23 13:29:24 OK 20260628120000_add_object_size_and_stats.sql (25.81ms)10722026/09/23 13:29:24 OK 20260905000000_add_claims.sql (21.02ms)10732026/09/23 13:29:24 OK 20260905000000_add_claims.sql (21.26ms)10742026/09/23 13:29:24 OK 20260905000000_add_claims.sql (22.31ms)10752026/09/23 13:29:24 OK 20260920000000_drop_claims.sql (3.17ms)10762026/09/23 13:29:24 OK 20260920000000_drop_claims.sql (3.15ms)10772026/09/23 13:29:24 OK 20260920000000_drop_claims.sql (3.17ms)10782026/09/23 13:29:24 OK 20260923120000_add_pushes.sql (2.23ms)10792026/09/23 13:29:24 goose: successfully migrated database to version: 2026092312000010802026/09/23 13:29:24 OK 20260923120000_add_pushes.sql (2.28ms)10812026/09/23 13:29:24 goose: successfully migrated database to version: 2026092312000010822026/09/23 13:29:24 OK 20260923120000_add_pushes.sql (1.95ms)10832026/09/23 13:29:24 goose: successfully migrated database to version: 2026092312000010842026/09/23 13:29:24 OK 1_commit_pending_closure.sql (2.09ms)10852026/09/23 13:29:24 OK 1_commit_pending_closure.sql (2.14ms)10862026/09/23 13:29:24 OK 1_commit_pending_closure.sql (2.12ms)10872026/09/23 13:29:24 OK 2_object_stats_trigger.sql (656.58µs)10882026/09/23 13:29:24 OK 2_object_stats_trigger.sql (663.71µs)10892026/09/23 13:29:24 OK 2_object_stats_trigger.sql (658.25µs)10902026/09/23 13:29:24 OK 3_commit_push.sql (583.63µs)10912026/09/23 13:29:24 goose: up to current file version: 310922026/09/23 13:29:24 OK 3_commit_push.sql (513.08µs)10932026/09/23 13:29:24 goose: up to current file version: 310942026/09/23 13:29:24 OK 3_commit_push.sql (569.08µs)10952026/09/23 13:29:24 goose: up to current file version: 310962026-09-23 13:29:24.193 UTC [63177] ERROR: relation "goose_db_version" does not exist at character 3610972026-09-23 13:29:24.193 UTC [63177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10982026-09-23 13:29:24.261 UTC [63178] ERROR: relation "goose_db_version" does not exist at character 3610992026-09-23 13:29:24.261 UTC [63178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11002026/09/23 13:29:24 OK 20241026095416_initial_model.sql (50.25ms)11012026/09/23 13:29:24 OK 20251210153512_drop_unused_gin_index.sql (10.3ms)11022026/09/23 13:29:24 OK 20251218171726_add_pins.sql (9.7ms)11032026/09/23 13:29:24 OK 20260628120000_add_object_size_and_stats.sql (22.54ms)11042026/09/23 13:29:24 OK 20260905000000_add_claims.sql (31.01ms)11052026/09/23 13:29:24 OK 20260920000000_drop_claims.sql (17.66ms)1106--- PASS: TestReadRedirectKeepsNarinfoProxied (1.93s)1107=== CONT TestReadProxy40411082026/09/23 13:29:24 OK 20260923120000_add_pushes.sql (24.71ms)11092026/09/23 13:29:24 goose: successfully migrated database to version: 2026092312000011102026/09/23 13:29:24 OK 1_commit_pending_closure.sql (2.12ms)11112026/09/23 13:29:24 OK 2_object_stats_trigger.sql (433.21µs)11122026/09/23 13:29:24 OK 3_commit_push.sql (382.42µs)11132026/09/23 13:29:24 goose: up to current file version: 311142026/09/23 13:29:24 OK 20241026095416_initial_model.sql (112.58ms)11152026/09/23 13:29:24 OK 20251210153512_drop_unused_gin_index.sql (9.56ms)11162026/09/23 13:29:24 OK 20251218171726_add_pins.sql (18.74ms)11172026/09/23 13:29:24 OK 20260628120000_add_object_size_and_stats.sql (25.08ms)11182026/09/23 13:29:24 OK 20260905000000_add_claims.sql (12.46ms)11192026/09/23 13:29:24 OK 20260920000000_drop_claims.sql (20.49ms)11202026/09/23 13:29:24 OK 20260923120000_add_pushes.sql (4.77ms)11212026/09/23 13:29:24 goose: successfully migrated database to version: 2026092312000011222026/09/23 13:29:24 OK 1_commit_pending_closure.sql (2.52ms)11232026/09/23 13:29:24 OK 2_object_stats_trigger.sql (1.21ms)11242026/09/23 13:29:24 OK 3_commit_push.sql (1.23ms)11252026/09/23 13:29:24 goose: up to current file version: 311262026/09/23 13:29:24 INFO Received uploads request method=POST path=/api/pending_closures11272026-09-23 13:29:24.620 UTC [63181] ERROR: relation "goose_db_version" does not exist at character 3611282026-09-23 13:29:24.620 UTC [63181] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11292026/09/23 13:29:24 INFO Received push request method=POST path=/api/pushes11302026/09/23 13:29:24 OK 20241026095416_initial_model.sql (123.72ms)11312026/09/23 13:29:24 OK 20251210153512_drop_unused_gin_index.sql (12.57ms)11322026/09/23 13:29:24 OK 20251218171726_add_pins.sql (53.81ms)1133--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.54s)1134=== CONT TestPush_CompleteCommitsEveryRoot11352026/09/23 13:29:24 OK 20260628120000_add_object_size_and_stats.sql (27.99ms)11362026-09-23 13:29:24.907 UTC [63184] ERROR: relation "goose_db_version" does not exist at character 3611372026-09-23 13:29:24.907 UTC [63184] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11382026/09/23 13:29:24 OK 20260905000000_add_claims.sql (19.12ms)11392026/09/23 13:29:24 OK 20260920000000_drop_claims.sql (23.7ms)11402026/09/23 13:29:24 OK 20260923120000_add_pushes.sql (5.6ms)11412026/09/23 13:29:24 goose: successfully migrated database to version: 2026092312000011422026/09/23 13:29:24 OK 1_commit_pending_closure.sql (1.66ms)11432026/09/23 13:29:24 OK 2_object_stats_trigger.sql (396.17µs)11442026/09/23 13:29:24 OK 3_commit_push.sql (361.96µs)11452026/09/23 13:29:24 goose: up to current file version: 31146--- PASS: TestReadRedirectNar (2.21s)1147=== CONT TestUploadHandlersRejectInvalidKeys1148=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1149=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1150=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1151=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1152=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1153=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1154=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1155=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1156=== CONT TestReadRedirectUsesPublicS3URL11572026/09/23 13:29:25 OK 20241026095416_initial_model.sql (124.54ms)11582026/09/23 13:29:25 OK 20251210153512_drop_unused_gin_index.sql (12.98ms)11592026/09/23 13:29:25 OK 20251218171726_add_pins.sql (27.64ms)11602026/09/23 13:29:25 OK 20260628120000_add_object_size_and_stats.sql (26.33ms)11612026/09/23 13:29:25 OK 20260905000000_add_claims.sql (21.55ms)11622026/09/23 13:29:25 OK 20260920000000_drop_claims.sql (32.21ms)11632026/09/23 13:29:25 OK 20260923120000_add_pushes.sql (6.34ms)11642026/09/23 13:29:25 goose: successfully migrated database to version: 2026092312000011652026/09/23 13:29:25 OK 1_commit_pending_closure.sql (2.64ms)11662026/09/23 13:29:25 OK 2_object_stats_trigger.sql (472.54µs)11672026/09/23 13:29:25 OK 3_commit_push.sql (431.17µs)11682026/09/23 13:29:25 goose: up to current file version: 311692026-09-23 13:29:25.239 UTC [63189] ERROR: relation "goose_db_version" does not exist at character 3611702026-09-23 13:29:25.239 UTC [63189] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1171--- PASS: TestReadProxyDisabled (2.23s)1172=== CONT TestService_NativeMTLS11732026-09-23 13:29:25.381 UTC [63192] ERROR: relation "goose_db_version" does not exist at character 3611742026-09-23 13:29:25.381 UTC [63192] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/09/23 13:29:25 OK 20241026095416_initial_model.sql (98.74ms)11762026/09/23 13:29:25 OK 20251210153512_drop_unused_gin_index.sql (11.03ms)11772026/09/23 13:29:25 OK 20251218171726_add_pins.sql (24.7ms)11782026/09/23 13:29:25 OK 20260628120000_add_object_size_and_stats.sql (34.34ms)1179--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.16s)1180=== CONT TestGCTaskStore_GetEmpty1181--- PASS: TestGCTaskStore_GetEmpty (0.00s)1182=== CONT TestReadProxyNarinfoAlreadyDecompressed11832026/09/23 13:29:25 OK 20260905000000_add_claims.sql (56.74ms)11842026/09/23 13:29:25 OK 20260920000000_drop_claims.sql (26.18ms)11852026/09/23 13:29:25 OK 20241026095416_initial_model.sql (127.66ms)11862026/09/23 13:29:25 OK 20260923120000_add_pushes.sql (5.43ms)11872026/09/23 13:29:25 goose: successfully migrated database to version: 2026092312000011882026/09/23 13:29:25 OK 1_commit_pending_closure.sql (2.1ms)11892026/09/23 13:29:25 OK 2_object_stats_trigger.sql (514.75µs)11902026/09/23 13:29:25 OK 3_commit_push.sql (458.38µs)11912026/09/23 13:29:25 goose: up to current file version: 311922026/09/23 13:29:25 OK 20251210153512_drop_unused_gin_index.sql (15.56ms)11932026/09/23 13:29:25 OK 20251218171726_add_pins.sql (36.47ms)11942026/09/23 13:29:25 OK 20260628120000_add_object_size_and_stats.sql (40.93ms)11952026/09/23 13:29:25 OK 20260905000000_add_claims.sql (45.43ms)11962026/09/23 13:29:25 OK 20260920000000_drop_claims.sql (20ms)11972026/09/23 13:29:25 OK 20260923120000_add_pushes.sql (11.76ms)11982026/09/23 13:29:25 goose: successfully migrated database to version: 2026092312000011992026/09/23 13:29:25 OK 1_commit_pending_closure.sql (3.27ms)12002026/09/23 13:29:25 OK 2_object_stats_trigger.sql (618.13µs)12012026/09/23 13:29:25 OK 3_commit_push.sql (418.71µs)12022026/09/23 13:29:25 goose: up to current file version: 31203--- PASS: TestReadProxyConditionalGet (2.01s)1204=== CONT TestReadProxyNarinfo12052026-09-23 13:29:25.850 UTC [63200] ERROR: relation "goose_db_version" does not exist at character 3612062026-09-23 13:29:25.850 UTC [63200] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1207--- PASS: TestReadProxyHead (2.05s)1208=== CONT TestMetricsInventory12092026/09/23 13:29:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12102026/09/23 13:29:26 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWVjZmI4MmEtZDFiMi00YTFmLWJhNTctYzY5OGMzZmY1Mjg1LjQ0YjQwZTBjLWQ4MjQtNGU3Mi1iNmI5LWI3ZDIzNmI2MzIwMngxNzkwMTcwMTY0NTc4MjU2MDAw parts=1212112026/09/23 13:29:26 INFO Received uploads request method=POST path=/api/pending_closures1212--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.86s)1213=== CONT TestMultipartCleanup12142026/09/23 13:29:26 OK 20241026095416_initial_model.sql (185.44ms)12152026/09/23 13:29:26 OK 20251210153512_drop_unused_gin_index.sql (17.71ms)12162026/09/23 13:29:26 OK 20251218171726_add_pins.sql (36.74ms)12172026/09/23 13:29:26 OK 20260628120000_add_object_size_and_stats.sql (35.3ms)12182026/09/23 13:29:26 OK 20260905000000_add_claims.sql (43.2ms)12192026/09/23 13:29:26 OK 20260920000000_drop_claims.sql (28.45ms)1220--- PASS: TestReadProxyInvalidPath (2.15s)1221=== CONT TestGenerateLandingPage1222--- PASS: TestGenerateLandingPage (0.00s)1223=== CONT TestNARDeduplicationMetadataUploadBug12242026/09/23 13:29:26 OK 20260923120000_add_pushes.sql (30.4ms)12252026/09/23 13:29:26 goose: successfully migrated database to version: 2026092312000012262026/09/23 13:29:26 OK 1_commit_pending_closure.sql (2.53ms)12272026/09/23 13:29:26 OK 2_object_stats_trigger.sql (477.92µs)12282026/09/23 13:29:26 OK 3_commit_push.sql (408.46µs)12292026/09/23 13:29:26 goose: up to current file version: 31230--- PASS: TestReadProxy404 (2.21s)1231=== CONT TestService_readinessHandler12322026-09-23 13:29:26.645 UTC [63209] ERROR: relation "goose_db_version" does not exist at character 3612332026-09-23 13:29:26.645 UTC [63209] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12342026-09-23 13:29:26.678 UTC [63210] ERROR: relation "goose_db_version" does not exist at character 3612352026-09-23 13:29:26.678 UTC [63210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12362026/09/23 13:29:26 OK 20241026095416_initial_model.sql (89.05ms)12372026/09/23 13:29:26 OK 20251210153512_drop_unused_gin_index.sql (3.37ms)12382026/09/23 13:29:26 OK 20251218171726_add_pins.sql (12.21ms)12392026-09-23 13:29:26.808 UTC [63211] ERROR: relation "goose_db_version" does not exist at character 3612402026-09-23 13:29:26.808 UTC [63211] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12412026/09/23 13:29:26 OK 20260628120000_add_object_size_and_stats.sql (25.14ms)12422026/09/23 13:29:26 OK 20241026095416_initial_model.sql (74.19ms)12432026/09/23 13:29:26 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)12442026/09/23 13:29:26 OK 20260905000000_add_claims.sql (34.3ms)12452026/09/23 13:29:26 OK 20251218171726_add_pins.sql (4.2ms)12462026/09/23 13:29:26 OK 20260920000000_drop_claims.sql (3.3ms)12472026/09/23 13:29:26 OK 20260923120000_add_pushes.sql (1.87ms)12482026/09/23 13:29:26 goose: successfully migrated database to version: 2026092312000012492026/09/23 13:29:26 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)12502026/09/23 13:29:26 OK 1_commit_pending_closure.sql (3.79ms)12512026/09/23 13:29:26 OK 2_object_stats_trigger.sql (1.78ms)12522026/09/23 13:29:26 OK 3_commit_push.sql (897.29µs)12532026/09/23 13:29:26 goose: up to current file version: 312542026/09/23 13:29:26 OK 20260905000000_add_claims.sql (7.36ms)12552026/09/23 13:29:26 OK 20260920000000_drop_claims.sql (34.5ms)12562026/09/23 13:29:26 OK 20260923120000_add_pushes.sql (11.42ms)12572026/09/23 13:29:26 goose: successfully migrated database to version: 2026092312000012582026/09/23 13:29:26 OK 1_commit_pending_closure.sql (2.92ms)12592026/09/23 13:29:26 OK 2_object_stats_trigger.sql (717.54µs)12602026/09/23 13:29:26 OK 3_commit_push.sql (499.54µs)12612026/09/23 13:29:26 goose: up to current file version: 312622026/09/23 13:29:26 OK 20241026095416_initial_model.sql (66.97ms)12632026/09/23 13:29:26 OK 20251210153512_drop_unused_gin_index.sql (12.87ms)12642026/09/23 13:29:26 OK 20251218171726_add_pins.sql (19.61ms)12652026/09/23 13:29:26 OK 20260628120000_add_object_size_and_stats.sql (22.17ms)12662026-09-23 13:29:26.987 UTC [63212] ERROR: relation "goose_db_version" does not exist at character 3612672026-09-23 13:29:26.987 UTC [63212] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12682026/09/23 13:29:26 OK 20260905000000_add_claims.sql (19.63ms)12692026/09/23 13:29:27 OK 20260920000000_drop_claims.sql (14.66ms)12702026/09/23 13:29:27 OK 20260923120000_add_pushes.sql (4.82ms)12712026/09/23 13:29:27 goose: successfully migrated database to version: 2026092312000012722026/09/23 13:29:27 OK 1_commit_pending_closure.sql (3.15ms)12732026/09/23 13:29:27 OK 2_object_stats_trigger.sql (589.92µs)12742026/09/23 13:29:27 OK 3_commit_push.sql (373.67µs)12752026/09/23 13:29:27 goose: up to current file version: 312762026/09/23 13:29:27 INFO Received push request method=POST path=/api/pushes12772026/09/23 13:29:27 INFO Received complete push request method=POST path=/api/pushes/1/complete1278--- PASS: TestPush_CompleteCommitsEveryRoot (2.33s)1279=== CONT TestIsValidCachePath1280=== RUN TestIsValidCachePath/narinfo1281=== PAUSE TestIsValidCachePath/narinfo1282=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1283=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1284=== RUN TestIsValidCachePath/nar_zst1285=== PAUSE TestIsValidCachePath/nar_zst1286=== RUN TestIsValidCachePath/nar_xz1287=== PAUSE TestIsValidCachePath/nar_xz1288=== RUN TestIsValidCachePath/nar_bz21289=== PAUSE TestIsValidCachePath/nar_bz21290=== RUN TestIsValidCachePath/nar_uncompressed1291=== PAUSE TestIsValidCachePath/nar_uncompressed1292=== RUN TestIsValidCachePath/ls1293=== PAUSE TestIsValidCachePath/ls1294=== RUN TestIsValidCachePath/log1295=== PAUSE TestIsValidCachePath/log1296=== RUN TestIsValidCachePath/realisation1297=== PAUSE TestIsValidCachePath/realisation1298=== RUN TestIsValidCachePath/nix-cache-info1299=== PAUSE TestIsValidCachePath/nix-cache-info1300=== RUN TestIsValidCachePath/index.html1301=== PAUSE TestIsValidCachePath/index.html1302=== RUN TestIsValidCachePath/traversal_parent1303=== PAUSE TestIsValidCachePath/traversal_parent1304=== RUN TestIsValidCachePath/traversal_in_middle1305=== PAUSE TestIsValidCachePath/traversal_in_middle1306=== RUN TestIsValidCachePath/invalid_char_e1307=== PAUSE TestIsValidCachePath/invalid_char_e1308=== RUN TestIsValidCachePath/invalid_char_u1309=== PAUSE TestIsValidCachePath/invalid_char_u1310=== RUN TestIsValidCachePath/random_path1311=== PAUSE TestIsValidCachePath/random_path1312=== RUN TestIsValidCachePath/empty1313=== PAUSE TestIsValidCachePath/empty1314=== RUN TestIsValidCachePath/leading_slash1315=== PAUSE TestIsValidCachePath/leading_slash1316=== RUN TestIsValidCachePath/wrong_extension1317=== PAUSE TestIsValidCachePath/wrong_extension1318=== RUN TestIsValidCachePath/short_hash1319=== PAUSE TestIsValidCachePath/short_hash1320=== CONT TestProxyHeadersOnlyTrustedOnSocket13212026/09/23 13:29:27 OK 20241026095416_initial_model.sql (224.68ms)13222026/09/23 13:29:27 OK 20251210153512_drop_unused_gin_index.sql (8.12ms)13232026/09/23 13:29:27 OK 20251218171726_add_pins.sql (28.32ms)13242026/09/23 13:29:27 OK 20260628120000_add_object_size_and_stats.sql (37.12ms)13252026/09/23 13:29:27 OK 20260905000000_add_claims.sql (52.41ms)13262026/09/23 13:29:27 OK 20260920000000_drop_claims.sql (33.01ms)13272026/09/23 13:29:27 OK 20260923120000_add_pushes.sql (25.32ms)13282026/09/23 13:29:27 goose: successfully migrated database to version: 2026092312000013292026/09/23 13:29:27 OK 1_commit_pending_closure.sql (4.05ms)13302026/09/23 13:29:27 OK 2_object_stats_trigger.sql (1.33ms)13312026/09/23 13:29:27 OK 3_commit_push.sql (1.28ms)13322026/09/23 13:29:27 goose: up to current file version: 31333--- PASS: TestReadRedirectUsesPublicS3URL (2.39s)1334=== CONT TestParseSingleRange1335=== RUN TestParseSingleRange/none1336=== PAUSE TestParseSingleRange/none1337=== RUN TestParseSingleRange/unknown_unit1338=== PAUSE TestParseSingleRange/unknown_unit1339=== RUN TestParseSingleRange/multi-range_ignored1340=== PAUSE TestParseSingleRange/multi-range_ignored1341=== RUN TestParseSingleRange/malformed_no_dash1342=== PAUSE TestParseSingleRange/malformed_no_dash1343=== RUN TestParseSingleRange/malformed_both_empty1344=== PAUSE TestParseSingleRange/malformed_both_empty1345=== RUN TestParseSingleRange/malformed_end_before_start1346=== PAUSE TestParseSingleRange/malformed_end_before_start1347=== RUN TestParseSingleRange/closed1348=== PAUSE TestParseSingleRange/closed1349=== RUN TestParseSingleRange/open-ended1350=== PAUSE TestParseSingleRange/open-ended1351=== RUN TestParseSingleRange/end_clamped_to_size1352=== PAUSE TestParseSingleRange/end_clamped_to_size1353=== RUN TestParseSingleRange/suffix1354=== PAUSE TestParseSingleRange/suffix1355=== RUN TestParseSingleRange/suffix_exceeds_size1356=== PAUSE TestParseSingleRange/suffix_exceeds_size1357=== RUN TestParseSingleRange/single_byte1358=== PAUSE TestParseSingleRange/single_byte1359=== RUN TestParseSingleRange/start_past_EOF1360=== PAUSE TestParseSingleRange/start_past_EOF1361=== RUN TestParseSingleRange/start_far_past_EOF1362=== PAUSE TestParseSingleRange/start_far_past_EOF1363=== CONT TestCreatePin_ReservedPins13642026-09-23 13:29:27.519 UTC [63216] ERROR: relation "goose_db_version" does not exist at character 3613652026-09-23 13:29:27.519 UTC [63216] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13662026/09/23 13:29:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58816/oidc13672026/09/23 13:29:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13682026/09/23 13:29:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1369--- PASS: TestService_NativeMTLS (2.41s)1370=== CONT TestResurrectedObjectNotDeleted13712026/09/23 13:29:27 OK 20241026095416_initial_model.sql (143.81ms)13722026/09/23 13:29:27 OK 20251210153512_drop_unused_gin_index.sql (16.25ms)13732026/09/23 13:29:27 WARN Rate limiter enabled after throttle name=s3-test rate=513742026/09/23 13:29:27 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1375=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1376 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101377 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001378--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.79s)1379=== CONT TestOrphanedObjectsGCStressTest13802026-09-23 13:29:27.783 UTC [63221] ERROR: relation "goose_db_version" does not exist at character 3613812026-09-23 13:29:27.783 UTC [63221] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13822026/09/23 13:29:27 OK 20251218171726_add_pins.sql (29.91ms)13832026/09/23 13:29:27 OK 20260628120000_add_object_size_and_stats.sql (19.77ms)13842026-09-23 13:29:27.806 UTC [63224] ERROR: relation "goose_db_version" does not exist at character 3613852026-09-23 13:29:27.806 UTC [63224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13862026/09/23 13:29:27 OK 20260905000000_add_claims.sql (17.53ms)13872026-09-23 13:29:27.820 UTC [63225] ERROR: relation "goose_db_version" does not exist at character 3613882026-09-23 13:29:27.820 UTC [63225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13892026/09/23 13:29:27 OK 20260920000000_drop_claims.sql (15.97ms)13902026/09/23 13:29:27 OK 20260923120000_add_pushes.sql (8.09ms)13912026/09/23 13:29:27 goose: successfully migrated database to version: 2026092312000013922026/09/23 13:29:27 OK 1_commit_pending_closure.sql (2.38ms)13932026/09/23 13:29:27 OK 2_object_stats_trigger.sql (414.5µs)13942026/09/23 13:29:27 OK 3_commit_push.sql (341.38µs)13952026/09/23 13:29:27 goose: up to current file version: 313962026/09/23 13:29:27 OK 20241026095416_initial_model.sql (103.14ms)13972026/09/23 13:29:27 OK 20251210153512_drop_unused_gin_index.sql (14.19ms)1398--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.44s)1399=== CONT TestService_healthCheckHandler14002026/09/23 13:29:27 OK 20251218171726_add_pins.sql (21.24ms)14012026/09/23 13:29:27 OK 20260628120000_add_object_size_and_stats.sql (42.54ms)14022026/09/23 13:29:28 OK 20241026095416_initial_model.sql (197.08ms)14032026/09/23 13:29:28 OK 20241026095416_initial_model.sql (203.84ms)14042026/09/23 13:29:28 OK 20251210153512_drop_unused_gin_index.sql (14.02ms)14052026/09/23 13:29:28 OK 20251210153512_drop_unused_gin_index.sql (13.01ms)14062026/09/23 13:29:28 OK 20260905000000_add_claims.sql (71.23ms)14072026/09/23 13:29:28 OK 20251218171726_add_pins.sql (16.71ms)14082026/09/23 13:29:28 OK 20251218171726_add_pins.sql (26.86ms)14092026/09/23 13:29:28 OK 20260920000000_drop_claims.sql (30.61ms)14102026/09/23 13:29:28 OK 20260628120000_add_object_size_and_stats.sql (46.05ms)14112026/09/23 13:29:28 OK 20260923120000_add_pushes.sql (24.22ms)14122026/09/23 13:29:28 goose: successfully migrated database to version: 2026092312000014132026/09/23 13:29:28 OK 1_commit_pending_closure.sql (5.44ms)14142026/09/23 13:29:28 OK 20260628120000_add_object_size_and_stats.sql (37.76ms)14152026/09/23 13:29:28 OK 2_object_stats_trigger.sql (1.99ms)14162026/09/23 13:29:28 OK 3_commit_push.sql (841.17µs)14172026/09/23 13:29:28 goose: up to current file version: 314182026/09/23 13:29:28 OK 20260905000000_add_claims.sql (59.34ms)14192026/09/23 13:29:28 OK 20260905000000_add_claims.sql (62.92ms)14202026/09/23 13:29:28 OK 20260920000000_drop_claims.sql (41.48ms)14212026/09/23 13:29:28 OK 20260920000000_drop_claims.sql (30.01ms)14222026/09/23 13:29:28 OK 20260923120000_add_pushes.sql (9.09ms)14232026/09/23 13:29:28 goose: successfully migrated database to version: 2026092312000014242026/09/23 13:29:28 OK 1_commit_pending_closure.sql (3.86ms)14252026/09/23 13:29:28 OK 2_object_stats_trigger.sql (956.88µs)14262026/09/23 13:29:28 OK 3_commit_push.sql (685.75µs)14272026/09/23 13:29:28 goose: up to current file version: 314282026/09/23 13:29:28 OK 20260923120000_add_pushes.sql (29.38ms)14292026/09/23 13:29:28 goose: successfully migrated database to version: 2026092312000014302026/09/23 13:29:28 OK 1_commit_pending_closure.sql (4.15ms)14312026/09/23 13:29:28 OK 2_object_stats_trigger.sql (1.97ms)14322026/09/23 13:29:28 OK 3_commit_push.sql (865.96µs)14332026/09/23 13:29:28 goose: up to current file version: 31434--- PASS: TestReadProxyNarinfo (2.50s)1435=== CONT TestOrphanedObjectsGC14362026-09-23 13:29:28.498 UTC [63230] ERROR: relation "goose_db_version" does not exist at character 3614372026-09-23 13:29:28.498 UTC [63230] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1438--- PASS: TestMetricsInventory (2.59s)1439=== CONT TestCreatePendingClosureRejectsOversizedNAR14402026/09/23 13:29:28 INFO Received uploads request method=POST path=/api/pending_closures1441--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1442=== CONT TestObjectStatsTrigger14432026/09/23 13:29:28 INFO Received uploads request method=POST path=/api/pending_closures14442026/09/23 13:29:28 OK 20241026095416_initial_model.sql (263.68ms)14452026/09/23 13:29:28 OK 20251210153512_drop_unused_gin_index.sql (11.36ms)14462026/09/23 13:29:28 OK 20251218171726_add_pins.sql (27.41ms)14472026/09/23 13:29:28 OK 20260628120000_add_object_size_and_stats.sql (57.61ms)14482026/09/23 13:29:28 OK 20260905000000_add_claims.sql (56.57ms)14492026/09/23 13:29:29 OK 20260920000000_drop_claims.sql (28.73ms)14502026/09/23 13:29:29 INFO Received cleanup request method=DELETE path=/api/pending_closures14512026/09/23 13:29:29 INFO Aborted multipart uploads count=114522026/09/23 13:29:29 OK 20260923120000_add_pushes.sql (34.39ms)14532026/09/23 13:29:29 goose: successfully migrated database to version: 202609231200001454--- PASS: TestMultipartCleanup (2.93s)1455=== CONT TestCacheConfigHandlerMaxNarSize1456--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1457=== CONT TestGracefulShutdownDrainsInflight14582026/09/23 13:29:29 INFO Starting HTTP server address=127.0.0.1:5882814592026/09/23 13:29:29 INFO Shutdown signal received, draining in-flight requests timeout=10s14602026/09/23 13:29:29 OK 1_commit_pending_closure.sql (5.34ms)14612026/09/23 13:29:29 OK 2_object_stats_trigger.sql (1.49ms)14622026/09/23 13:29:29 OK 3_commit_push.sql (894µs)14632026/09/23 13:29:29 goose: up to current file version: 31464--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1465=== CONT TestGCTaskStore_Fail1466--- PASS: TestGCTaskStore_Fail (0.00s)1467=== CONT TestGCTaskStore_GetReturnsLatest1468--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1469=== CONT TestServerTLSConfig1470=== RUN TestServerTLSConfig/no_client_CA1471=== PAUSE TestServerTLSConfig/no_client_CA1472=== RUN TestServerTLSConfig/missing_CA_file1473=== PAUSE TestServerTLSConfig/missing_CA_file1474=== RUN TestServerTLSConfig/not_a_PEM_file1475=== PAUSE TestServerTLSConfig/not_a_PEM_file1476=== CONT TestLeadEndsOnShutdown1477=== NAME TestNARDeduplicationMetadataUploadBug1478 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-62986-3424006005/TestNARDeduplicationMetadataUploadBug3427282816/001/store/gi9xr0y7d29bf3i4bq6x0sanakajij1c-file1.txt14792026-09-23 13:29:29.482 UTC [63238] ERROR: relation "goose_db_version" does not exist at character 3614802026-09-23 13:29:29.482 UTC [63238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14812026/09/23 13:29:29 WARN readiness check failed error="closed pool"1482--- PASS: TestService_readinessHandler (2.91s)1483=== CONT TestGCTaskStore_ConflictDifferentParams1484--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1485=== CONT TestGCTaskStore_DeduplicateSameParams1486--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1487=== CONT TestGCTaskStore_CompletedAllowsNewTask1488--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1489=== CONT TestGCTaskStore_StartNew1490--- PASS: TestGCTaskStore_StartNew (0.00s)1491=== CONT TestGCTaskStore_PhaseUpdates1492--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1493=== CONT TestGCMetrics14942026-09-23 13:29:29.518 UTC [63243] ERROR: relation "goose_db_version" does not exist at character 3614952026-09-23 13:29:29.518 UTC [63243] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14962026-09-23 13:29:29.522 UTC [63245] ERROR: relation "goose_db_version" does not exist at character 3614972026-09-23 13:29:29.522 UTC [63245] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14982026-09-23 13:29:29.525 UTC [63246] ERROR: relation "goose_db_version" does not exist at character 3614992026-09-23 13:29:29.525 UTC [63246] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15002026/09/23 13:29:29 OK 20241026095416_initial_model.sql (17.98ms)15012026/09/23 13:29:29 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)15022026/09/23 13:29:29 OK 20251218171726_add_pins.sql (6.54ms)15032026-09-23 13:29:29.545 UTC [63248] ERROR: relation "goose_db_version" does not exist at character 3615042026-09-23 13:29:29.545 UTC [63248] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026/09/23 13:29:29 INFO Received push request method=POST path=/api/pushes15062026/09/23 13:29:29 OK 20260628120000_add_object_size_and_stats.sql (10.6ms)15072026/09/23 13:29:29 OK 20241026095416_initial_model.sql (19ms)15082026/09/23 13:29:29 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)15092026/09/23 13:29:29 OK 20241026095416_initial_model.sql (19.94ms)15102026/09/23 13:29:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15112026/09/23 13:29:29 INFO Uploading gi9xr0y7d29bf3i4bq6x0sanakajij1c-file1.txt (160B)15122026/09/23 13:29:29 OK 20251210153512_drop_unused_gin_index.sql (435.29µs)15132026/09/23 13:29:29 OK 20260905000000_add_claims.sql (2.36ms)15142026/09/23 13:29:29 OK 20251218171726_add_pins.sql (1.31ms)15152026/09/23 13:29:29 OK 20241026095416_initial_model.sql (21.12ms)15162026/09/23 13:29:29 OK 20260920000000_drop_claims.sql (1.21ms)15172026/09/23 13:29:29 WARN Failed to register uploaded object key=gi9xr0y7d29bf3i4bq6x0sanakajij1c.ls error="server returned 404: 404 page not found\n"15182026/09/23 13:29:29 OK 20251210153512_drop_unused_gin_index.sql (934.83µs)15192026/09/23 13:29:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15202026/09/23 13:29:29 INFO Signed narinfos id=1 count=115212026/09/23 13:29:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15222026/09/23 13:29:29 INFO Uploading 1 narinfos15232026/09/23 13:29:29 OK 20260923120000_add_pushes.sql (1.22ms)15242026/09/23 13:29:29 goose: successfully migrated database to version: 2026092312000015252026/09/23 13:29:29 OK 20251218171726_add_pins.sql (3.32ms)15262026/09/23 13:29:29 OK 1_commit_pending_closure.sql (984.21µs)15272026/09/23 13:29:29 OK 2_object_stats_trigger.sql (234.58µs)15282026/09/23 13:29:29 OK 3_commit_push.sql (194.5µs)15292026/09/23 13:29:29 goose: up to current file version: 315302026/09/23 13:29:29 INFO Received complete push request method=POST path=/api/pushes/1/complete15312026/09/23 13:29:29 WARN Failed to register uploaded object key=gi9xr0y7d29bf3i4bq6x0sanakajij1c.narinfo error="server returned 404: 404 page not found\n"15322026/09/23 13:29:29 OK 20260628120000_add_object_size_and_stats.sql (31.22ms)15332026/09/23 13:29:29 OK 20251218171726_add_pins.sql (44.09ms)15342026/09/23 13:29:29 OK 20260628120000_add_object_size_and_stats.sql (49.88ms)15352026/09/23 13:29:29 INFO Upload complete. (104ms)1536=== NAME TestNARDeduplicationMetadataUploadBug1537 metadata_upload_test.go:54: Retrieved narinfo from S3:1538 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestNARDeduplicationMetadataUploadBug3427282816/001/store/gi9xr0y7d29bf3i4bq6x0sanakajij1c-file1.txt1539 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1540 Compression: zstd1541 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1542 NarSize: 1601543 References: 1544 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1545 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1546 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1547 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15482026/09/23 13:29:29 OK 20260628120000_add_object_size_and_stats.sql (22.29ms)15492026/09/23 13:29:29 OK 20260905000000_add_claims.sql (37.51ms)15502026/09/23 13:29:29 OK 20260905000000_add_claims.sql (36.88ms)15512026/09/23 13:29:29 OK 20260920000000_drop_claims.sql (21.02ms)15522026/09/23 13:29:29 OK 20241026095416_initial_model.sql (97.21ms)15532026/09/23 13:29:29 OK 20260920000000_drop_claims.sql (16.68ms)15542026/09/23 13:29:29 OK 20260905000000_add_claims.sql (38.37ms)15552026/09/23 13:29:29 OK 20251210153512_drop_unused_gin_index.sql (10.49ms)15562026/09/23 13:29:29 OK 20260923120000_add_pushes.sql (23.8ms)15572026/09/23 13:29:29 goose: successfully migrated database to version: 2026092312000015582026/09/23 13:29:29 OK 20260923120000_add_pushes.sql (8.72ms)15592026/09/23 13:29:29 goose: successfully migrated database to version: 2026092312000015602026/09/23 13:29:29 OK 20260920000000_drop_claims.sql (9.97ms)1561 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-62986-3424006005/TestNARDeduplicationMetadataUploadBug3427282816/001/store/dznfav5jiyxp8mck321plambm23bp67w-file2.txt15622026/09/23 13:29:29 OK 20251218171726_add_pins.sql (13.42ms)15632026/09/23 13:29:29 OK 1_commit_pending_closure.sql (6.29ms)15642026/09/23 13:29:29 OK 1_commit_pending_closure.sql (5.38ms)15652026/09/23 13:29:29 OK 2_object_stats_trigger.sql (333µs)15662026/09/23 13:29:29 OK 2_object_stats_trigger.sql (402µs)15672026/09/23 13:29:29 OK 3_commit_push.sql (201.38µs)15682026/09/23 13:29:29 goose: up to current file version: 315692026/09/23 13:29:29 OK 3_commit_push.sql (192.33µs)15702026/09/23 13:29:29 goose: up to current file version: 315712026/09/23 13:29:29 OK 20260923120000_add_pushes.sql (17.07ms)15722026/09/23 13:29:29 goose: successfully migrated database to version: 2026092312000015732026/09/23 13:29:29 OK 1_commit_pending_closure.sql (1.35ms)15742026/09/23 13:29:29 OK 2_object_stats_trigger.sql (249.46µs)15752026/09/23 13:29:29 OK 3_commit_push.sql (173.21µs)15762026/09/23 13:29:29 goose: up to current file version: 315772026/09/23 13:29:29 OK 20260628120000_add_object_size_and_stats.sql (29.53ms)15782026/09/23 13:29:29 OK 20260905000000_add_claims.sql (8.27ms)15792026/09/23 13:29:29 OK 20260920000000_drop_claims.sql (5.74ms)15802026/09/23 13:29:29 OK 20260923120000_add_pushes.sql (6.41ms)15812026/09/23 13:29:29 goose: successfully migrated database to version: 2026092312000015822026/09/23 13:29:29 OK 1_commit_pending_closure.sql (735.54µs)15832026/09/23 13:29:29 OK 2_object_stats_trigger.sql (199.21µs)15842026/09/23 13:29:29 OK 3_commit_push.sql (160.46µs)15852026/09/23 13:29:29 goose: up to current file version: 315862026/09/23 13:29:29 INFO Received push request method=POST path=/api/pushes15872026/09/23 13:29:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15882026/09/23 13:29:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15892026/09/23 13:29:29 INFO Signed narinfos id=2 count=115902026/09/23 13:29:29 INFO Uploading 1 narinfos15912026/09/23 13:29:29 WARN Failed to register uploaded object key=dznfav5jiyxp8mck321plambm23bp67w.ls error="server returned 404: 404 page not found\n"15922026/09/23 13:29:29 INFO Received complete push request method=POST path=/api/pushes/2/complete15932026/09/23 13:29:29 WARN Failed to register uploaded object key=dznfav5jiyxp8mck321plambm23bp67w.narinfo error="server returned 404: 404 page not found\n"15942026/09/23 13:29:29 INFO Upload complete. (71ms)1595 metadata_upload_test.go:76: Retrieved narinfo from S3:1596 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestNARDeduplicationMetadataUploadBug3427282816/001/store/dznfav5jiyxp8mck321plambm23bp67w-file2.txt1597 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1598 Compression: zstd1599 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1600 NarSize: 1601601 References: 1602 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1603 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1604 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1605 {"version":1,"root":{"type":"regular","size":44}}16062026/09/23 13:29:29 INFO Starting HTTP server address=127.0.0.1:5884016072026/09/23 13:29:29 INFO Starting HTTP server address=/nix/var/nix/builds/nix-62986-3424006005/TestProxyHeadersOnlyTrustedOnSocket1945620417/001/proxy.sock16082026/09/23 13:29:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"16092026/09/23 13:29:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1610--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.58s)1611=== CONT TestGCBugBareHashReferences1612--- PASS: TestNARDeduplicationMetadataUploadBug (3.54s)1613=== CONT TestClientFallsBackToClosures16142026-09-23 13:29:29.897 UTC [63259] ERROR: relation "goose_db_version" does not exist at character 3616152026-09-23 13:29:29.897 UTC [63259] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16162026/09/23 13:29:30 OK 20241026095416_initial_model.sql (121.63ms)1617--- PASS: TestResurrectedObjectNotDeleted (2.39s)1618=== CONT TestLeadElectsOneAndHandsOver16192026/09/23 13:29:30 OK 20251210153512_drop_unused_gin_index.sql (13.99ms)16202026/09/23 13:29:30 OK 20251218171726_add_pins.sql (30.36ms)16212026/09/23 13:29:30 OK 20260628120000_add_object_size_and_stats.sql (27.09ms)16222026/09/23 13:29:30 OK 20260905000000_add_claims.sql (20.5ms)16232026/09/23 13:29:30 OK 20260920000000_drop_claims.sql (28.69ms)16242026-09-23 13:29:30.185 UTC [63262] ERROR: relation "goose_db_version" does not exist at character 3616252026-09-23 13:29:30.185 UTC [63262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16262026/09/23 13:29:30 OK 20260923120000_add_pushes.sql (5.23ms)16272026/09/23 13:29:30 goose: successfully migrated database to version: 2026092312000016282026/09/23 13:29:30 OK 1_commit_pending_closure.sql (3.06ms)16292026/09/23 13:29:30 OK 2_object_stats_trigger.sql (857.71µs)16302026/09/23 13:29:30 OK 3_commit_push.sql (466µs)16312026/09/23 13:29:30 goose: up to current file version: 316322026/09/23 13:29:30 OK 20241026095416_initial_model.sql (204.67ms)16332026/09/23 13:29:30 OK 20251210153512_drop_unused_gin_index.sql (16.46ms)16342026/09/23 13:29:30 OK 20251218171726_add_pins.sql (43.12ms)16352026/09/23 13:29:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16362026/09/23 13:29:30 WARN Refused reserved pin name=worker-x86_64-linux16372026/09/23 13:29:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16382026/09/23 13:29:30 INFO Received create pin request method=POST path=/api/pins/my-app16392026/09/23 13:29:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16402026/09/23 13:29:30 OK 20260628120000_add_object_size_and_stats.sql (26.28ms)1641--- PASS: TestCreatePin_ReservedPins (3.10s)1642=== CONT TestResolveDBConnectionString1643=== RUN TestResolveDBConnectionString/flag_wins1644=== PAUSE TestResolveDBConnectionString/flag_wins1645=== RUN TestResolveDBConnectionString/file_when_flag_empty1646=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1647=== RUN TestResolveDBConnectionString/missing_file_is_an_error1648=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1649=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1650=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1651=== RUN TestResolveDBConnectionString/nothing_configured1652=== PAUSE TestResolveDBConnectionString/nothing_configured1653=== CONT TestClientSharedPathCommittedMidPush16542026/09/23 13:29:30 OK 20260905000000_add_claims.sql (77.52ms)16552026/09/23 13:29:30 OK 20260920000000_drop_claims.sql (15.25ms)16562026-09-23 13:29:30.647 UTC [63265] ERROR: relation "goose_db_version" does not exist at character 3616572026-09-23 13:29:30.647 UTC [63265] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16582026/09/23 13:29:30 OK 20260923120000_add_pushes.sql (4.72ms)16592026/09/23 13:29:30 goose: successfully migrated database to version: 2026092312000016602026/09/23 13:29:30 OK 1_commit_pending_closure.sql (2.92ms)16612026/09/23 13:29:30 OK 2_object_stats_trigger.sql (703.08µs)16622026/09/23 13:29:30 OK 3_commit_push.sql (472.25µs)16632026/09/23 13:29:30 goose: up to current file version: 31664--- PASS: TestService_healthCheckHandler (2.80s)1665=== CONT TestClientWithDependencies16662026/09/23 13:29:30 OK 20241026095416_initial_model.sql (140.26ms)16672026/09/23 13:29:30 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)16682026/09/23 13:29:30 OK 20251218171726_add_pins.sql (27.01ms)16692026-09-23 13:29:30.865 UTC [63268] ERROR: relation "goose_db_version" does not exist at character 3616702026-09-23 13:29:30.865 UTC [63268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16712026/09/23 13:29:30 OK 20260628120000_add_object_size_and_stats.sql (29.55ms)16722026/09/23 13:29:30 OK 20260905000000_add_claims.sql (45.68ms)16732026/09/23 13:29:30 OK 20260920000000_drop_claims.sql (50.49ms)16742026/09/23 13:29:30 OK 20260923120000_add_pushes.sql (19.11ms)16752026/09/23 13:29:30 goose: successfully migrated database to version: 2026092312000016762026/09/23 13:29:31 OK 1_commit_pending_closure.sql (4.9ms)16772026/09/23 13:29:31 OK 2_object_stats_trigger.sql (806.54µs)16782026/09/23 13:29:31 OK 3_commit_push.sql (691.29µs)16792026/09/23 13:29:31 goose: up to current file version: 316802026/09/23 13:29:31 OK 20241026095416_initial_model.sql (206.9ms)16812026/09/23 13:29:31 OK 20251210153512_drop_unused_gin_index.sql (18.24ms)16822026/09/23 13:29:31 OK 20251218171726_add_pins.sql (22.72ms)16832026/09/23 13:29:31 OK 20260628120000_add_object_size_and_stats.sql (41.57ms)16842026/09/23 13:29:31 OK 20260905000000_add_claims.sql (56.11ms)16852026/09/23 13:29:31 OK 20260920000000_drop_claims.sql (44.23ms)16862026/09/23 13:29:31 OK 20260923120000_add_pushes.sql (17.81ms)16872026/09/23 13:29:31 goose: successfully migrated database to version: 2026092312000016882026/09/23 13:29:31 OK 1_commit_pending_closure.sql (4.75ms)16892026/09/23 13:29:31 OK 2_object_stats_trigger.sql (1.31ms)16902026/09/23 13:29:31 OK 3_commit_push.sql (1.88ms)16912026/09/23 13:29:31 goose: up to current file version: 31692--- PASS: TestObjectStatsTrigger (2.86s)1693=== CONT TestClientPushesUseOnePush16942026-09-23 13:29:31.471 UTC [63269] ERROR: relation "goose_db_version" does not exist at character 3616952026-09-23 13:29:31.471 UTC [63269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16962026-09-23 13:29:31.575 UTC [63272] ERROR: relation "goose_db_version" does not exist at character 3616972026-09-23 13:29:31.575 UTC [63272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16982026/09/23 13:29:31 INFO lead: acquired remote=192.0.2.1:123416992026/09/23 13:29:31 INFO lead: released remote=192.0.2.1:12341700--- PASS: TestLeadEndsOnShutdown (2.56s)1701=== CONT TestPinProtectsFromGC17022026/09/23 13:29:31 OK 20241026095416_initial_model.sql (170.26ms)17032026/09/23 13:29:31 OK 20251210153512_drop_unused_gin_index.sql (14.05ms)17042026/09/23 13:29:31 OK 20251218171726_add_pins.sql (31.21ms)1705=== NAME TestOrphanedObjectsGC1706 orphaned_objects_gc_test.go:290: GC Test Summary:1707 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1708 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1709 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1710 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1711 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1712--- PASS: TestOrphanedObjectsGC (3.52s)1713=== CONT TestClientCADerivations17142026/09/23 13:29:31 OK 20260628120000_add_object_size_and_stats.sql (37.08ms)17152026/09/23 13:29:31 OK 20241026095416_initial_model.sql (174.95ms)17162026/09/23 13:29:31 OK 20251210153512_drop_unused_gin_index.sql (10.13ms)17172026/09/23 13:29:31 OK 20260905000000_add_claims.sql (58.77ms)17182026/09/23 13:29:31 OK 20251218171726_add_pins.sql (23.57ms)17192026/09/23 13:29:31 OK 20260920000000_drop_claims.sql (25.6ms)17202026/09/23 13:29:31 OK 20260923120000_add_pushes.sql (22.36ms)17212026/09/23 13:29:31 goose: successfully migrated database to version: 2026092312000017222026/09/23 13:29:31 OK 1_commit_pending_closure.sql (2.59ms)17232026/09/23 13:29:31 OK 2_object_stats_trigger.sql (588.13µs)17242026/09/23 13:29:31 OK 3_commit_push.sql (369.46µs)17252026/09/23 13:29:31 goose: up to current file version: 317262026/09/23 13:29:31 OK 20260628120000_add_object_size_and_stats.sql (46.83ms)17272026-09-23 13:29:31.925 UTC [63277] ERROR: relation "goose_db_version" does not exist at character 3617282026-09-23 13:29:31.925 UTC [63277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17292026/09/23 13:29:31 OK 20260905000000_add_claims.sql (67.31ms)17302026/09/23 13:29:31 INFO Aborted multipart uploads count=017312026/09/23 13:29:31 WARN Force mode enabled - objects will be deleted immediately without grace period17322026/09/23 13:29:31 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=017332026/09/23 13:29:31 INFO Vacuumed table table=pending_closures17342026/09/23 13:29:31 INFO Vacuumed table table=pending_objects17352026/09/23 13:29:31 OK 20260920000000_drop_claims.sql (19.74ms)17362026/09/23 13:29:32 INFO Vacuumed table table=multipart_uploads17372026/09/23 13:29:32 INFO Vacuumed table table=closures17382026/09/23 13:29:32 INFO Vacuumed table table=objects1739--- PASS: TestGCMetrics (2.52s)1740=== CONT TestCacheConfigHandler1741=== RUN TestCacheConfigHandler/full_config,_no_issuer1742=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1743=== RUN TestCacheConfigHandler/no_cache_url_configured1744=== PAUSE TestCacheConfigHandler/no_cache_url_configured1745=== RUN TestCacheConfigHandler/no_signing_keys1746=== PAUSE TestCacheConfigHandler/no_signing_keys1747=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1748=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1749=== CONT TestCacheStatsHandler17502026/09/23 13:29:32 OK 20260923120000_add_pushes.sql (22.97ms)17512026/09/23 13:29:32 goose: successfully migrated database to version: 2026092312000017522026/09/23 13:29:32 OK 1_commit_pending_closure.sql (2.72ms)17532026/09/23 13:29:32 OK 2_object_stats_trigger.sql (462.79µs)17542026/09/23 13:29:32 OK 3_commit_push.sql (454.33µs)17552026/09/23 13:29:32 goose: up to current file version: 317562026/09/23 13:29:32 OK 20241026095416_initial_model.sql (139.31ms)17572026/09/23 13:29:32 OK 20251210153512_drop_unused_gin_index.sql (9.31ms)17582026/09/23 13:29:32 OK 20251218171726_add_pins.sql (35.95ms)17592026/09/23 13:29:32 OK 20260628120000_add_object_size_and_stats.sql (39.01ms)17602026/09/23 13:29:32 OK 20260905000000_add_claims.sql (55.08ms)17612026/09/23 13:29:32 OK 20260920000000_drop_claims.sql (39.46ms)17622026/09/23 13:29:32 OK 20260923120000_add_pushes.sql (27.95ms)17632026/09/23 13:29:32 goose: successfully migrated database to version: 2026092312000017642026/09/23 13:29:32 OK 1_commit_pending_closure.sql (6.6ms)17652026/09/23 13:29:32 OK 2_object_stats_trigger.sql (1.12ms)17662026/09/23 13:29:32 OK 3_commit_push.sql (722.42µs)17672026/09/23 13:29:32 goose: up to current file version: 31768--- PASS: TestGCBugBareHashReferences (2.75s)1769=== CONT TestClientErrorHandling1770=== RUN TestClientErrorHandling/InvalidStorePath1771=== PAUSE TestClientErrorHandling/InvalidStorePath1772=== RUN TestClientErrorHandling/InvalidAuthToken1773=== PAUSE TestClientErrorHandling/InvalidAuthToken1774=== RUN TestClientErrorHandling/ServerNotAvailable1775=== PAUSE TestClientErrorHandling/ServerNotAvailable1776=== CONT TestClientMultipleUploads17772026-09-23 13:29:32.632 UTC [63283] ERROR: relation "goose_db_version" does not exist at character 3617782026-09-23 13:29:32.632 UTC [63283] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17792026-09-23 13:29:32.638 UTC [63284] ERROR: relation "goose_db_version" does not exist at character 3617802026-09-23 13:29:32.638 UTC [63284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17812026/09/23 13:29:32 INFO lead: acquired remote=192.0.2.1:123417822026/09/23 13:29:32 OK 20241026095416_initial_model.sql (145.47ms)17832026/09/23 13:29:32 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)17842026/09/23 13:29:32 OK 20241026095416_initial_model.sql (162.29ms)17852026/09/23 13:29:32 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)17862026/09/23 13:29:32 OK 20251218171726_add_pins.sql (16.77ms)17872026/09/23 13:29:32 OK 20251218171726_add_pins.sql (13.01ms)17882026/09/23 13:29:32 OK 20260628120000_add_object_size_and_stats.sql (21.93ms)17892026/09/23 13:29:32 OK 20260628120000_add_object_size_and_stats.sql (25.44ms)17902026/09/23 13:29:32 OK 20260905000000_add_claims.sql (24.24ms)17912026/09/23 13:29:32 OK 20260920000000_drop_claims.sql (11.51ms)17922026/09/23 13:29:32 OK 20260923120000_add_pushes.sql (20.66ms)17932026/09/23 13:29:32 goose: successfully migrated database to version: 2026092312000017942026/09/23 13:29:32 OK 20260905000000_add_claims.sql (40.71ms)17952026/09/23 13:29:32 OK 1_commit_pending_closure.sql (1.04ms)17962026/09/23 13:29:32 OK 2_object_stats_trigger.sql (269.29µs)17972026/09/23 13:29:32 OK 3_commit_push.sql (189.75µs)17982026/09/23 13:29:32 goose: up to current file version: 317992026/09/23 13:29:32 OK 20260920000000_drop_claims.sql (28.55ms)18002026/09/23 13:29:32 OK 20260923120000_add_pushes.sql (15.38ms)18012026/09/23 13:29:32 goose: successfully migrated database to version: 2026092312000018022026/09/23 13:29:32 OK 1_commit_pending_closure.sql (910.13µs)18032026/09/23 13:29:32 OK 2_object_stats_trigger.sql (221.25µs)18042026/09/23 13:29:32 OK 3_commit_push.sql (193.29µs)18052026/09/23 13:29:32 goose: up to current file version: 318062026/09/23 13:29:32 INFO lead: released remote=192.0.2.1:123418072026/09/23 13:29:33 INFO lead: acquired remote=192.0.2.1:123418082026/09/23 13:29:33 INFO lead: released remote=192.0.2.1:12341809--- PASS: TestLeadElectsOneAndHandsOver (2.95s)1810=== CONT TestClientIntegration18112026/09/23 13:29:33 INFO Received uploads request method=POST path=/api/pending_closures18122026/09/23 13:29:33 INFO Received uploads request method=POST path=/api/pending_closures18132026/09/23 13:29:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18142026/09/23 13:29:33 INFO Uploading 9hsfyagzghn6w22ddbawsb8mdbwrgxhf-shared-dep (136B)18152026/09/23 13:29:33 INFO Uploading i60wqrzl71hx76qwrcyma35i06hy443i-b (248B)18162026-09-23 13:29:33.091 UTC [63298] ERROR: relation "goose_db_version" does not exist at character 3618172026-09-23 13:29:33.091 UTC [63298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18182026/09/23 13:29:33 WARN Failed to register uploaded object key=1zmhrsffvg8xd7w55dlg2gw43br8zqnw.ls error="server returned 404: 404 page not found\n"18192026/09/23 13:29:33 WARN Failed to register uploaded object key=9hsfyagzghn6w22ddbawsb8mdbwrgxhf.ls error="server returned 404: 404 page not found\n"18202026/09/23 13:29:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18212026/09/23 13:29:33 WARN Failed to register uploaded object key=nar/1mn33d5f6l22qwmkxq4649ndlfp1jf8xn499n42a2n9ac79zhkdf.nar.zst error="server returned 404: 404 page not found\n"18222026/09/23 13:29:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18232026/09/23 13:29:33 WARN Failed to register uploaded object key=i60wqrzl71hx76qwrcyma35i06hy443i.ls error="server returned 404: 404 page not found\n"18242026/09/23 13:29:33 INFO Signed narinfos id=1 count=218252026/09/23 13:29:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18262026/09/23 13:29:33 INFO Signed narinfos id=2 count=218272026/09/23 13:29:33 INFO Uploading 4 narinfos18282026/09/23 13:29:33 WARN Failed to register uploaded object key=9hsfyagzghn6w22ddbawsb8mdbwrgxhf.narinfo error="server returned 404: 404 page not found\n"18292026/09/23 13:29:33 WARN Failed to register uploaded object key=i60wqrzl71hx76qwrcyma35i06hy443i.narinfo error="server returned 404: 404 page not found\n"18302026/09/23 13:29:33 WARN Failed to register uploaded object key=1zmhrsffvg8xd7w55dlg2gw43br8zqnw.narinfo error="server returned 404: 404 page not found\n"18312026/09/23 13:29:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18322026/09/23 13:29:33 WARN Failed to register uploaded object key=9hsfyagzghn6w22ddbawsb8mdbwrgxhf.narinfo error="server returned 404: 404 page not found\n"18332026/09/23 13:29:33 INFO Completed upload id=118342026/09/23 13:29:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18352026/09/23 13:29:33 INFO Completed upload id=218362026/09/23 13:29:33 INFO Upload complete. (160ms)1837=== NAME TestClientFallsBackToClosures1838 client_pushes_test.go:112: Retrieved narinfo from S3:1839 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientFallsBackToClosures2285392811/001/store/9hsfyagzghn6w22ddbawsb8mdbwrgxhf-shared-dep1840 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1841 Compression: zstd1842 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821843 NarSize: 1361844 References: 1845 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1846 client_pushes_test.go:112: Retrieved narinfo from S3:1847 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientFallsBackToClosures2285392811/001/store/1zmhrsffvg8xd7w55dlg2gw43br8zqnw-a1848 URL: nar/1mn33d5f6l22qwmkxq4649ndlfp1jf8xn499n42a2n9ac79zhkdf.nar.zst1849 Compression: zstd1850 NarHash: sha256:1mn33d5f6l22qwmkxq4649ndlfp1jf8xn499n42a2n9ac79zhkdf1851 NarSize: 2481852 References: /nix/var/nix/builds/nix-62986-3424006005/TestClientFallsBackToClosures2285392811/001/store/9hsfyagzghn6w22ddbawsb8mdbwrgxhf-shared-dep1853 CA: text:sha256:0wpmkzighv051rr10yy8mal0zqgyqk6sfp6pz1c7s2n1dcki97bc1854 client_pushes_test.go:112: Retrieved narinfo from S3:1855 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientFallsBackToClosures2285392811/001/store/i60wqrzl71hx76qwrcyma35i06hy443i-b1856 URL: nar/1mn33d5f6l22qwmkxq4649ndlfp1jf8xn499n42a2n9ac79zhkdf.nar.zst1857 Compression: zstd1858 NarHash: sha256:1mn33d5f6l22qwmkxq4649ndlfp1jf8xn499n42a2n9ac79zhkdf1859 NarSize: 2481860 References: /nix/var/nix/builds/nix-62986-3424006005/TestClientFallsBackToClosures2285392811/001/store/9hsfyagzghn6w22ddbawsb8mdbwrgxhf-shared-dep1861 CA: text:sha256:0wpmkzighv051rr10yy8mal0zqgyqk6sfp6pz1c7s2n1dcki97bc1862--- PASS: TestClientFallsBackToClosures (3.41s)1863=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18642026/09/23 13:29:33 OK 20241026095416_initial_model.sql (184.21ms)18652026/09/23 13:29:33 OK 20251210153512_drop_unused_gin_index.sql (9.82ms)18662026/09/23 13:29:33 OK 20251218171726_add_pins.sql (24.03ms)18672026/09/23 13:29:33 OK 20260628120000_add_object_size_and_stats.sql (36ms)18682026/09/23 13:29:33 OK 20260905000000_add_claims.sql (49.43ms)18692026/09/23 13:29:33 OK 20260920000000_drop_claims.sql (10.08ms)18702026-09-23 13:29:33.470 UTC [63305] ERROR: relation "goose_db_version" does not exist at character 3618712026-09-23 13:29:33.470 UTC [63305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18722026/09/23 13:29:33 OK 20260923120000_add_pushes.sql (7.01ms)18732026/09/23 13:29:33 goose: successfully migrated database to version: 2026092312000018742026/09/23 13:29:33 OK 1_commit_pending_closure.sql (902.08µs)18752026/09/23 13:29:33 OK 2_object_stats_trigger.sql (226.96µs)18762026/09/23 13:29:33 OK 3_commit_push.sql (192.29µs)18772026/09/23 13:29:33 goose: up to current file version: 318782026-09-23 13:29:33.530 UTC [63309] ERROR: relation "goose_db_version" does not exist at character 3618792026-09-23 13:29:33.530 UTC [63309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18802026-09-23 13:29:33.645 UTC [63311] ERROR: relation "goose_db_version" does not exist at character 3618812026-09-23 13:29:33.645 UTC [63311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18822026/09/23 13:29:33 OK 20241026095416_initial_model.sql (142.53ms)1883=== NAME TestClientWithDependencies1884 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-62986-3424006005/TestClientWithDependencies2797408788/001/store/lj2pg7hm1l4psq9i1x7hvjdw5izwr2cb-test-script18852026/09/23 13:29:33 OK 20251210153512_drop_unused_gin_index.sql (11.83ms)18862026/09/23 13:29:33 OK 20251218171726_add_pins.sql (17.94ms)1887 client_integration_test.go:615: Found 1 dependencies (including self)18882026/09/23 13:29:33 OK 20260628120000_add_object_size_and_stats.sql (29.84ms)18892026/09/23 13:29:33 OK 20241026095416_initial_model.sql (143.45ms)18902026/09/23 13:29:33 OK 20251210153512_drop_unused_gin_index.sql (5.38ms)18912026/09/23 13:29:33 OK 20260905000000_add_claims.sql (27.1ms)18922026/09/23 13:29:33 OK 20251218171726_add_pins.sql (9.73ms)18932026/09/23 13:29:33 OK 20260920000000_drop_claims.sql (10.49ms)18942026/09/23 13:29:33 OK 20260923120000_add_pushes.sql (1.28ms)18952026/09/23 13:29:33 goose: successfully migrated database to version: 2026092312000018962026/09/23 13:29:33 OK 1_commit_pending_closure.sql (1.39ms)18972026/09/23 13:29:33 OK 2_object_stats_trigger.sql (234.08µs)18982026/09/23 13:29:33 OK 3_commit_push.sql (188.13µs)18992026/09/23 13:29:33 goose: up to current file version: 319002026/09/23 13:29:33 OK 20260628120000_add_object_size_and_stats.sql (16.86ms)19012026/09/23 13:29:33 INFO Received push request method=POST path=/api/pushes19022026/09/23 13:29:33 OK 20241026095416_initial_model.sql (86.84ms)19032026/09/23 13:29:33 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)19042026/09/23 13:29:33 INFO Received push request method=POST path=/api/pushes19052026/09/23 13:29:33 OK 20260905000000_add_claims.sql (47.83ms)19062026/09/23 13:29:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19072026/09/23 13:29:33 INFO Uploading lj2pg7hm1l4psq9i1x7hvjdw5izwr2cb-test-script (136B)19082026/09/23 13:29:33 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19092026/09/23 13:29:33 INFO Uploading nsz1y10py5068ail0ngx24jvc6pjbh2p-shared-dep (136B)19102026/09/23 13:29:33 INFO Uploading 1478pv1609xpqr75wsl9bsx532ydh517-top (256B)19112026/09/23 13:29:33 OK 20260920000000_drop_claims.sql (16.21ms)19122026/09/23 13:29:33 OK 20251218171726_add_pins.sql (29.49ms)19132026/09/23 13:29:33 WARN Failed to register uploaded object key=lj2pg7hm1l4psq9i1x7hvjdw5izwr2cb.ls error="server returned 404: 404 page not found\n"19142026/09/23 13:29:33 WARN Failed to register uploaded object key=log/7sb5fjv93x8cid5ifwq1qz8ix3ja522j-test-script.drv error="server returned 404: 404 page not found\n"19152026/09/23 13:29:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19162026/09/23 13:29:33 INFO Signed narinfos id=1 count=119172026/09/23 13:29:33 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19182026/09/23 13:29:33 INFO Uploading 1 narinfos19192026/09/23 13:29:33 OK 20260923120000_add_pushes.sql (18.5ms)19202026/09/23 13:29:33 goose: successfully migrated database to version: 2026092312000019212026/09/23 13:29:33 OK 1_commit_pending_closure.sql (947µs)19222026/09/23 13:29:33 OK 2_object_stats_trigger.sql (231.92µs)19232026/09/23 13:29:33 OK 3_commit_push.sql (207.29µs)19242026/09/23 13:29:33 goose: up to current file version: 319252026/09/23 13:29:33 WARN Failed to register uploaded object key=1478pv1609xpqr75wsl9bsx532ydh517.ls error="server returned 404: 404 page not found\n"19262026/09/23 13:29:33 WARN Failed to register uploaded object key=nsz1y10py5068ail0ngx24jvc6pjbh2p.ls error="server returned 404: 404 page not found\n"19272026/09/23 13:29:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19282026/09/23 13:29:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19292026/09/23 13:29:33 WARN Failed to register uploaded object key=nar/14n9djw9bns2pkjdhq41bp1l7h07ivvsaypwi58xba6ycjkh1jqa.nar.zst error="server returned 404: 404 page not found\n"19302026/09/23 13:29:33 INFO Signed narinfos id=1 count=219312026/09/23 13:29:33 INFO Uploading 2 narinfos19322026/09/23 13:29:33 INFO Received complete push request method=POST path=/api/pushes/1/complete19332026/09/23 13:29:33 WARN Failed to register uploaded object key=lj2pg7hm1l4psq9i1x7hvjdw5izwr2cb.narinfo error="server returned 404: 404 page not found\n"19342026/09/23 13:29:33 OK 20260628120000_add_object_size_and_stats.sql (33.88ms)19352026/09/23 13:29:33 WARN Failed to register uploaded object key=1478pv1609xpqr75wsl9bsx532ydh517.narinfo error="server returned 404: 404 page not found\n"19362026/09/23 13:29:33 INFO Received complete push request method=POST path=/api/pushes/1/complete19372026/09/23 13:29:33 WARN Failed to register uploaded object key=nsz1y10py5068ail0ngx24jvc6pjbh2p.narinfo error="server returned 404: 404 page not found\n"19382026/09/23 13:29:33 INFO Upload complete. (161ms)1939 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-62986-3424006005/TestClientWithDependencies2797408788/001/store) requires matching store prefix19402026/09/23 13:29:33 INFO Upload complete. (154ms)1941=== NAME TestClientSharedPathCommittedMidPush1942 client_integration_test.go:680: Retrieved narinfo from S3:1943 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientSharedPathCommittedMidPush138924571/001/store/nsz1y10py5068ail0ngx24jvc6pjbh2p-shared-dep1944 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1945 Compression: zstd1946 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821947 NarSize: 1361948 References: 1949 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1950 client_integration_test.go:680: Retrieved narinfo from S3:1951 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientSharedPathCommittedMidPush138924571/001/store/1478pv1609xpqr75wsl9bsx532ydh517-top1952 URL: nar/14n9djw9bns2pkjdhq41bp1l7h07ivvsaypwi58xba6ycjkh1jqa.nar.zst1953 Compression: zstd1954 NarHash: sha256:14n9djw9bns2pkjdhq41bp1l7h07ivvsaypwi58xba6ycjkh1jqa1955 NarSize: 2561956 References: /nix/var/nix/builds/nix-62986-3424006005/TestClientSharedPathCommittedMidPush138924571/001/store/nsz1y10py5068ail0ngx24jvc6pjbh2p-shared-dep1957 CA: text:sha256:12vr6xmwn9v94b5qbnmihh1jknnb80irsdlnsanwbf7fxvypq7wz19582026/09/23 13:29:33 OK 20260905000000_add_claims.sql (58.26ms)19592026/09/23 13:29:33 OK 20260920000000_drop_claims.sql (31.05ms)1960--- PASS: TestClientWithDependencies (3.21s)1961=== CONT TestService_AuthMiddleware_OIDC19622026/09/23 13:29:33 OK 20260923120000_add_pushes.sql (6.16ms)19632026/09/23 13:29:33 goose: successfully migrated database to version: 2026092312000019642026/09/23 13:29:33 OK 1_commit_pending_closure.sql (871.42µs)19652026/09/23 13:29:33 OK 2_object_stats_trigger.sql (211.17µs)19662026/09/23 13:29:33 OK 3_commit_push.sql (190.04µs)19672026/09/23 13:29:33 goose: up to current file version: 31968--- PASS: TestClientSharedPathCommittedMidPush (3.42s)1969=== CONT TestService_RequireScope_OIDC19702026/09/23 13:29:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58882/oidc19712026-09-23 13:29:34.061 UTC [63337] ERROR: relation "goose_db_version" does not exist at character 3619722026-09-23 13:29:34.061 UTC [63337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19732026/09/23 13:29:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58886/oidc19742026/09/23 13:29:34 INFO Received push request method=POST path=/api/pushes19752026/09/23 13:29:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19762026/09/23 13:29:34 INFO Uploading fkm5wwvjyl3995b7lw7z4as443apy53n-b (248B)19772026/09/23 13:29:34 INFO Uploading mssafij5pr32rg4pf1hfznkhwpmpr86g-shared-dep (136B)19782026/09/23 13:29:34 WARN Failed to register uploaded object key=ipf2g47xn74kwc209pxspr76rqymrvnd.ls error="server returned 404: 404 page not found\n"19792026/09/23 13:29:34 WARN Failed to register uploaded object key=nar/0hc0pspmlafarzcaaq108dwjxs7h48v48iyxv9gndii2ng70yghh.nar.zst error="server returned 404: 404 page not found\n"19802026/09/23 13:29:34 WARN Failed to register uploaded object key=fkm5wwvjyl3995b7lw7z4as443apy53n.ls error="server returned 404: 404 page not found\n"19812026/09/23 13:29:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19822026/09/23 13:29:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19832026/09/23 13:29:34 WARN Failed to register uploaded object key=mssafij5pr32rg4pf1hfznkhwpmpr86g.ls error="server returned 404: 404 page not found\n"19842026/09/23 13:29:34 INFO Signed narinfos id=1 count=319852026/09/23 13:29:34 INFO Uploading 3 narinfos19862026/09/23 13:29:34 WARN Failed to register uploaded object key=mssafij5pr32rg4pf1hfznkhwpmpr86g.narinfo error="server returned 404: 404 page not found\n"19872026/09/23 13:29:34 WARN Failed to register uploaded object key=fkm5wwvjyl3995b7lw7z4as443apy53n.narinfo error="server returned 404: 404 page not found\n"19882026/09/23 13:29:34 INFO Received complete push request method=POST path=/api/pushes/1/complete19892026/09/23 13:29:34 WARN Failed to register uploaded object key=ipf2g47xn74kwc209pxspr76rqymrvnd.narinfo error="server returned 404: 404 page not found\n"19902026/09/23 13:29:34 INFO Upload complete. (135ms)1991=== NAME TestClientPushesUseOnePush1992 client_pushes_test.go:97: Retrieved narinfo from S3:1993 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientPushesUseOnePush3993190500/001/store/mssafij5pr32rg4pf1hfznkhwpmpr86g-shared-dep1994 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1995 Compression: zstd1996 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821997 NarSize: 1361998 References: 1999 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2000 client_pushes_test.go:97: Retrieved narinfo from S3:2001 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientPushesUseOnePush3993190500/001/store/ipf2g47xn74kwc209pxspr76rqymrvnd-a2002 URL: nar/0hc0pspmlafarzcaaq108dwjxs7h48v48iyxv9gndii2ng70yghh.nar.zst2003 Compression: zstd2004 NarHash: sha256:0hc0pspmlafarzcaaq108dwjxs7h48v48iyxv9gndii2ng70yghh2005 NarSize: 2482006 References: /nix/var/nix/builds/nix-62986-3424006005/TestClientPushesUseOnePush3993190500/001/store/mssafij5pr32rg4pf1hfznkhwpmpr86g-shared-dep2007 CA: text:sha256:0hvynv52vi4g8c7kbhznnhk6wdcn3zflvll81pn63dzp7vmp2rk52008 client_pushes_test.go:97: Retrieved narinfo from S3:2009 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientPushesUseOnePush3993190500/001/store/fkm5wwvjyl3995b7lw7z4as443apy53n-b2010 URL: nar/0hc0pspmlafarzcaaq108dwjxs7h48v48iyxv9gndii2ng70yghh.nar.zst2011 Compression: zstd2012 NarHash: sha256:0hc0pspmlafarzcaaq108dwjxs7h48v48iyxv9gndii2ng70yghh2013 NarSize: 2482014 References: /nix/var/nix/builds/nix-62986-3424006005/TestClientPushesUseOnePush3993190500/001/store/mssafij5pr32rg4pf1hfznkhwpmpr86g-shared-dep2015 CA: text:sha256:0hvynv52vi4g8c7kbhznnhk6wdcn3zflvll81pn63dzp7vmp2rk520162026/09/23 13:29:34 OK 20241026095416_initial_model.sql (161.99ms)20172026/09/23 13:29:34 OK 20251210153512_drop_unused_gin_index.sql (9.77ms)2018--- PASS: TestClientPushesUseOnePush (2.86s)2019=== CONT TestService_ReadAuthMiddleware20202026/09/23 13:29:34 OK 20251218171726_add_pins.sql (67.46ms)20212026/09/23 13:29:34 OK 20260628120000_add_object_size_and_stats.sql (46.19ms)20222026/09/23 13:29:34 OK 20260905000000_add_claims.sql (34.76ms)20232026/09/23 13:29:34 OK 20260920000000_drop_claims.sql (17.83ms)2024=== NAME TestClientCADerivations2025 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-62986-3424006005/TestClientCADerivations324802716/001/store/72amigp6jgsppn1g27774r8qpzm2pxni-ca-test20262026/09/23 13:29:34 OK 20260923120000_add_pushes.sql (5.91ms)20272026/09/23 13:29:34 goose: successfully migrated database to version: 2026092312000020282026/09/23 13:29:34 OK 1_commit_pending_closure.sql (854.67µs)20292026/09/23 13:29:34 OK 2_object_stats_trigger.sql (279.46µs)20302026/09/23 13:29:34 OK 3_commit_push.sql (226.58µs)20312026/09/23 13:29:34 goose: up to current file version: 32032 client_ca_test.go:139: Found 1 dependencies (including self)2033=== NAME TestPinProtectsFromGC2034 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-62986-3424006005/TestPinProtectsFromGC4071512666/001/store/b5cgkcqsz22q0jzmskyha2wr35g1fpli-pinned-file.txt2035 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-62986-3424006005/TestPinProtectsFromGC4071512666/001/store/fzijhgn54nbhh1wif9kshsw10vbdm17c-unpinned-file.txt2036--- PASS: TestCacheStatsHandler (2.57s)2037=== CONT TestService_AuthMiddleware_MTLSProxyHeader20382026-09-23 13:29:34.575 UTC [63372] ERROR: relation "goose_db_version" does not exist at character 3620392026-09-23 13:29:34.575 UTC [63372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20402026/09/23 13:29:34 INFO Received push request method=POST path=/api/pushes20412026/09/23 13:29:34 INFO Received push request method=POST path=/api/pushes20422026/09/23 13:29:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20432026/09/23 13:29:34 INFO Uploading b5cgkcqsz22q0jzmskyha2wr35g1fpli-pinned-file.txt (128B)20442026/09/23 13:29:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20452026/09/23 13:29:34 INFO Uploading 72amigp6jgsppn1g27774r8qpzm2pxni-ca-test (144B)20462026/09/23 13:29:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20472026/09/23 13:29:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20482026/09/23 13:29:34 WARN Failed to register uploaded object key=b5cgkcqsz22q0jzmskyha2wr35g1fpli.ls error="server returned 404: 404 page not found\n"20492026/09/23 13:29:34 INFO Signed narinfos id=1 count=120502026/09/23 13:29:34 INFO Uploading 1 narinfos20512026/09/23 13:29:34 WARN Failed to register uploaded object key=72amigp6jgsppn1g27774r8qpzm2pxni.ls error="server returned 404: 404 page not found\n"20522026/09/23 13:29:34 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20532026/09/23 13:29:34 INFO Received complete push request method=POST path=/api/pushes/1/complete20542026/09/23 13:29:34 WARN Failed to register uploaded object key=b5cgkcqsz22q0jzmskyha2wr35g1fpli.narinfo error="server returned 404: 404 page not found\n"20552026/09/23 13:29:34 WARN Failed to register uploaded object key=log/5smh37pyxjrzf5a1vknlyan4g7wrhq77-ca-test.drv error="server returned 404: 404 page not found\n"20562026/09/23 13:29:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20572026/09/23 13:29:34 INFO Signed narinfos id=1 count=120582026/09/23 13:29:34 INFO Uploading 1 narinfos20592026/09/23 13:29:34 INFO Upload complete. (142ms)20602026/09/23 13:29:34 INFO Received complete push request method=POST path=/api/pushes/1/complete20612026/09/23 13:29:34 WARN Failed to register uploaded object key=72amigp6jgsppn1g27774r8qpzm2pxni.narinfo error="server returned 404: 404 page not found\n"20622026/09/23 13:29:34 INFO Upload complete. (206ms)2063=== NAME TestClientCADerivations2064 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientCADerivations324802716/001/store/72amigp6jgsppn1g27774r8qpzm2pxni-ca-test2065 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2066 Compression: zstd2067 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2068 NarSize: 1442069 References: 2070 Deriver: /nix/var/nix/builds/nix-62986-3424006005/TestClientCADerivations324802716/001/store/5smh37pyxjrzf5a1vknlyan4g7wrhq77-ca-test.drv2071 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2072 client_ca_test.go:185: Checking for realisation files in S3...2073 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2074 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20752026-09-23 13:29:34.744 UTC [63398] ERROR: relation "goose_db_version" does not exist at character 3620762026-09-23 13:29:34.744 UTC [63398] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20772026/09/23 13:29:34 OK 20241026095416_initial_model.sql (142.66ms)20782026/09/23 13:29:34 OK 20251210153512_drop_unused_gin_index.sql (7.11ms)20792026/09/23 13:29:34 OK 20251218171726_add_pins.sql (11.2ms)2080 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket53?endpoint=http://localhost:58738®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-62986-3424006005/TestClientCADerivations324802716/001/store'2081 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120822026/09/23 13:29:34 INFO Received push request method=POST path=/api/pushes20832026/09/23 13:29:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20842026/09/23 13:29:34 INFO Uploading fzijhgn54nbhh1wif9kshsw10vbdm17c-unpinned-file.txt (128B)20852026/09/23 13:29:34 OK 20260628120000_add_object_size_and_stats.sql (18.04ms)20862026/09/23 13:29:34 WARN Failed to register uploaded object key=fzijhgn54nbhh1wif9kshsw10vbdm17c.ls error="server returned 404: 404 page not found\n"20872026/09/23 13:29:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20882026/09/23 13:29:34 INFO Signed narinfos id=2 count=120892026/09/23 13:29:34 INFO Uploading 1 narinfos20902026/09/23 13:29:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"2091--- PASS: TestClientCADerivations (3.04s)2092=== CONT TestService_ReadScope_PublicByDefault20932026/09/23 13:29:34 INFO Received complete push request method=POST path=/api/pushes/2/complete20942026/09/23 13:29:34 WARN Failed to register uploaded object key=fzijhgn54nbhh1wif9kshsw10vbdm17c.narinfo error="server returned 404: 404 page not found\n"20952026/09/23 13:29:34 INFO Upload complete. (80ms)20962026/09/23 13:29:34 OK 20260905000000_add_claims.sql (26.77ms)20972026/09/23 13:29:34 OK 20260920000000_drop_claims.sql (7.92ms)20982026/09/23 13:29:34 OK 20241026095416_initial_model.sql (63.83ms)20992026/09/23 13:29:34 OK 20260923120000_add_pushes.sql (11.66ms)21002026/09/23 13:29:34 goose: successfully migrated database to version: 2026092312000021012026/09/23 13:29:34 OK 20251210153512_drop_unused_gin_index.sql (9.4ms)21022026/09/23 13:29:34 OK 1_commit_pending_closure.sql (1.35ms)21032026/09/23 13:29:34 OK 2_object_stats_trigger.sql (223.08µs)21042026/09/23 13:29:34 OK 3_commit_push.sql (170.96µs)21052026/09/23 13:29:34 goose: up to current file version: 321062026/09/23 13:29:34 OK 20251218171726_add_pins.sql (15.09ms)21072026/09/23 13:29:34 INFO Received create pin request method=POST path=/api/pins/myapp21082026/09/23 13:29:34 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-62986-3424006005/TestPinProtectsFromGC4071512666/001/store/b5cgkcqsz22q0jzmskyha2wr35g1fpli-pinned-file.txt narinfo_key=b5cgkcqsz22q0jzmskyha2wr35g1fpli.narinfo21092026/09/23 13:29:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures21102026/09/23 13:29:34 INFO Garbage collection started21112026/09/23 13:29:34 INFO Aborted multipart uploads count=021122026/09/23 13:29:34 WARN Force mode enabled - objects will be deleted immediately without grace period21132026/09/23 13:29:34 OK 20260628120000_add_object_size_and_stats.sql (46.58ms)2114=== NAME TestClientMultipleUploads2115 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-62986-3424006005/TestClientMultipleUploads2771212157/001/store/fvszsj3899yz73wqpdq9x480yipl1sah-test-file-0.txt21162026/09/23 13:29:34 OK 20260905000000_add_claims.sql (47.27ms)21172026/09/23 13:29:34 OK 20260920000000_drop_claims.sql (22.6ms)21182026/09/23 13:29:34 OK 20260923120000_add_pushes.sql (13.92ms)21192026/09/23 13:29:34 goose: successfully migrated database to version: 2026092312000021202026/09/23 13:29:35 OK 1_commit_pending_closure.sql (941.88µs)21212026/09/23 13:29:35 OK 2_object_stats_trigger.sql (254.08µs)21222026/09/23 13:29:35 OK 3_commit_push.sql (204.33µs)21232026/09/23 13:29:35 goose: up to current file version: 32124 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-62986-3424006005/TestClientMultipleUploads2771212157/001/store/1facm0aai14m3jjj31w9d2prpynw8ayc-test-file-1.txt2125 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-62986-3424006005/TestClientMultipleUploads2771212157/001/store/yvbjp3aclnj6aj6n04anc8rnbicg5d27-test-file-2.txt2126=== NAME TestOrphanedObjectsGCStressTest2127 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains21282026/09/23 13:29:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=021292026/09/23 13:29:35 INFO Vacuumed table table=pending_closures2130 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21312026/09/23 13:29:35 INFO Vacuumed table table=pending_objects21322026/09/23 13:29:35 INFO Vacuumed table table=multipart_uploads21332026/09/23 13:29:35 INFO Received push request method=POST path=/api/pushes21342026/09/23 13:29:35 INFO Vacuumed table table=closures21352026/09/23 13:29:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21362026/09/23 13:29:35 INFO Uploading fvszsj3899yz73wqpdq9x480yipl1sah-test-file-0.txt (160B)21372026/09/23 13:29:35 INFO Uploading yvbjp3aclnj6aj6n04anc8rnbicg5d27-test-file-2.txt (160B)21382026/09/23 13:29:35 INFO Uploading 1facm0aai14m3jjj31w9d2prpynw8ayc-test-file-1.txt (160B)21392026/09/23 13:29:35 INFO Vacuumed table table=objects21402026/09/23 13:29:35 WARN Failed to register uploaded object key=1facm0aai14m3jjj31w9d2prpynw8ayc.ls error="server returned 404: 404 page not found\n"21412026/09/23 13:29:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21422026/09/23 13:29:35 WARN Failed to register uploaded object key=fvszsj3899yz73wqpdq9x480yipl1sah.ls error="server returned 404: 404 page not found\n"21432026/09/23 13:29:35 WARN Failed to register uploaded object key=yvbjp3aclnj6aj6n04anc8rnbicg5d27.ls error="server returned 404: 404 page not found\n"21442026/09/23 13:29:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21452026/09/23 13:29:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21462026/09/23 13:29:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21472026/09/23 13:29:35 INFO Signed narinfos id=1 count=321482026/09/23 13:29:35 INFO Uploading 3 narinfos2149=== NAME TestClientIntegration2150 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-62986-3424006005/TestClientIntegration1053392831/002/store/9927hwnn1xbnln3bf7a08knhrkh4zqxx-test-file.txt21512026/09/23 13:29:35 INFO Received complete push request method=POST path=/api/pushes/1/complete21522026/09/23 13:29:35 WARN Failed to register uploaded object key=yvbjp3aclnj6aj6n04anc8rnbicg5d27.narinfo error="server returned 404: 404 page not found\n"21532026/09/23 13:29:35 WARN Failed to register uploaded object key=fvszsj3899yz73wqpdq9x480yipl1sah.narinfo error="server returned 404: 404 page not found\n"21542026/09/23 13:29:35 WARN Failed to register uploaded object key=1facm0aai14m3jjj31w9d2prpynw8ayc.narinfo error="server returned 404: 404 page not found\n"21552026/09/23 13:29:35 INFO Upload complete. (164ms)2156=== NAME TestClientMultipleUploads2157 client_integration_test.go:369: Uploaded 3 paths in 201.071208ms21582026/09/23 13:29:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21592026/09/23 13:29:35 WARN mTLS auth: bound subjects configured but subject DN unavailable21602026/09/23 13:29:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2161--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.10s)2162=== CONT TestIsValidUploadKey/narinfo2163=== CONT TestIsValidUploadKey/realisation2164=== CONT TestIsValidUploadKey/build_log_equals2165=== CONT TestIsValidUploadKey/build_log_question_mark2166=== CONT TestIsValidUploadKey/realisation_plus_in_output2167=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2168=== CONT TestIsValidUploadKey/build_log_plus_in_name2169=== CONT TestIsValidUploadKey/build_log_home-manager_file2170=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2171=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2172=== CONT TestIsValidUploadKey/index.html2173=== CONT TestIsValidUploadKey/nix-cache-info2174=== CONT TestIsValidUploadKey/build_log2175=== CONT TestIsValidUploadKey/traversal2176=== CONT TestIsValidUploadKey/nar_xz2177=== CONT TestIsValidUploadKey/unknown_type2178=== CONT TestIsValidUploadKey/nar_zst2179=== CONT TestIsValidUploadKey/empty_key2180=== CONT TestIsValidUploadKey/absolute2181=== CONT TestIsValidUploadKey/traversal_nar2182=== CONT TestIsValidUploadKey/listing2183=== CONT TestIsValidUploadKey/nar_plain2184--- PASS: TestIsValidUploadKey (0.00s)2185 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2186 --- PASS: TestIsValidUploadKey/realisation (0.00s)2187 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2188 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2189 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2190 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2191 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2192 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2193 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2194 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2195 --- PASS: TestIsValidUploadKey/index.html (0.00s)2196 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2197 --- PASS: TestIsValidUploadKey/build_log (0.00s)2198 --- PASS: TestIsValidUploadKey/traversal (0.00s)2199 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2200 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2201 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2202 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2203 --- PASS: TestIsValidUploadKey/absolute (0.00s)2204 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2205 --- PASS: TestIsValidUploadKey/listing (0.00s)2206 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2207=== CONT TestProxyWriteTimeout/narinfo2208=== CONT TestProxyWriteTimeout/10_GiB_nar2209=== CONT TestProxyWriteTimeout/unknown_size2210=== CONT TestProxyWriteTimeout/1_GiB_nar2211--- PASS: TestProxyWriteTimeout (0.00s)2212 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2213 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2214 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2215 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2216=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22172026/09/23 13:29:35 INFO Received uploads request method=POST path=/22182026/09/23 13:29:35 INFO Received push request method=POST path=/api/pushes2219--- PASS: TestClientMultipleUploads (2.82s)2220=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22212026/09/23 13:29:35 INFO Received complete multipart upload request method=POST path=/2222=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22232026/09/23 13:29:35 INFO Received request for more parts method=POST path=/22242026/09/23 13:29:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22252026/09/23 13:29:35 INFO Uploading 9927hwnn1xbnln3bf7a08knhrkh4zqxx-test-file.txt (152B)22262026/09/23 13:29:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22272026/09/23 13:29:35 WARN Failed to register uploaded object key=9927hwnn1xbnln3bf7a08knhrkh4zqxx.ls error="server returned 404: 404 page not found\n"22282026/09/23 13:29:35 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"22292026/09/23 13:29:35 INFO Signed narinfos id=1 count=122302026/09/23 13:29:35 INFO Uploading 1 narinfos2231=== CONT TestPush_RejectsBadRequests/no_roots22322026/09/23 13:29:35 INFO Received push request method=POST path=/api/pushes2233=== CONT TestPush_RejectsBadRequests/bad_root22342026/09/23 13:29:35 INFO Received push request method=POST path=/api/pushes2235=== CONT TestPush_RejectsBadRequests/root_not_in_objects22362026/09/23 13:29:35 INFO Received push request method=POST path=/api/pushes2237=== CONT TestPush_RejectsBadRequests/no_objects22382026/09/23 13:29:35 INFO Received push request method=POST path=/api/pushes2239=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22402026/09/23 13:29:35 INFO Received uploads request method=POST path=/2241--- PASS: TestPush_RejectsBadRequests (2.15s)2242 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2243 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2244 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2245 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2246=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22472026/09/23 13:29:35 INFO Received complete multipart upload request method=POST path=/2248=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22492026/09/23 13:29:35 INFO Received request for more parts method=POST path=/2250=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22512026/09/23 13:29:35 INFO Received uploads request method=POST path=/2252--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2253 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2254 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2255 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2256 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2257=== CONT TestIsValidCachePath/narinfo2258=== CONT TestIsValidCachePath/index.html2259=== CONT TestIsValidCachePath/short_hash2260=== CONT TestIsValidCachePath/wrong_extension2261=== CONT TestIsValidCachePath/leading_slash2262=== CONT TestIsValidCachePath/empty2263=== CONT TestIsValidCachePath/random_path2264=== CONT TestIsValidCachePath/invalid_char_u2265=== CONT TestIsValidCachePath/invalid_char_e2266=== CONT TestIsValidCachePath/traversal_in_middle2267=== CONT TestIsValidCachePath/traversal_parent2268=== CONT TestIsValidCachePath/nar_uncompressed2269=== CONT TestIsValidCachePath/nix-cache-info2270=== CONT TestIsValidCachePath/realisation2271=== CONT TestIsValidCachePath/log2272=== CONT TestIsValidCachePath/ls2273=== CONT TestIsValidCachePath/nar_xz2274=== CONT TestIsValidCachePath/nar_bz22275=== CONT TestIsValidCachePath/nar_zst2276=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2277--- PASS: TestIsValidCachePath (0.00s)2278 --- PASS: TestIsValidCachePath/narinfo (0.00s)2279 --- PASS: TestIsValidCachePath/index.html (0.00s)2280 --- PASS: TestIsValidCachePath/short_hash (0.00s)2281 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2282 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2283 --- PASS: TestIsValidCachePath/empty (0.00s)2284 --- PASS: TestIsValidCachePath/random_path (0.00s)2285 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2286 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2287 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2288 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2289 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2290 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2291 --- PASS: TestIsValidCachePath/realisation (0.00s)2292 --- PASS: TestIsValidCachePath/log (0.00s)2293 --- PASS: TestIsValidCachePath/ls (0.00s)2294 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2295 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2296 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2297 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2298=== CONT TestParseSingleRange/none2299=== CONT TestParseSingleRange/open-ended2300=== CONT TestParseSingleRange/start_far_past_EOF2301=== CONT TestParseSingleRange/start_past_EOF2302=== CONT TestParseSingleRange/single_byte2303=== CONT TestParseSingleRange/suffix_exceeds_size2304=== CONT TestParseSingleRange/suffix2305=== CONT TestParseSingleRange/end_clamped_to_size2306=== CONT TestParseSingleRange/malformed_both_empty2307=== CONT TestParseSingleRange/closed2308=== CONT TestParseSingleRange/malformed_end_before_start2309=== CONT TestParseSingleRange/multi-range_ignored2310=== CONT TestParseSingleRange/malformed_no_dash2311=== CONT TestParseSingleRange/unknown_unit2312--- PASS: TestParseSingleRange (0.00s)2313 --- PASS: TestParseSingleRange/none (0.00s)2314 --- PASS: TestParseSingleRange/open-ended (0.00s)2315 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2316 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2317 --- PASS: TestParseSingleRange/single_byte (0.00s)2318 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2319 --- PASS: TestParseSingleRange/suffix (0.00s)2320 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2321 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2322 --- PASS: TestParseSingleRange/closed (0.00s)2323 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2324 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2325 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2326 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2327=== CONT TestServerTLSConfig/no_client_CA2328=== CONT TestServerTLSConfig/not_a_PEM_file2329=== CONT TestServerTLSConfig/missing_CA_file2330--- PASS: TestServerTLSConfig (0.00s)2331 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2332 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2333 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2334=== CONT TestResolveDBConnectionString/flag_wins2335=== CONT TestResolveDBConnectionString/missing_file_is_an_error2336=== CONT TestResolveDBConnectionString/file_when_flag_empty2337=== CONT TestResolveDBConnectionString/nothing_configured2338=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2339=== CONT TestCacheConfigHandler/full_config,_no_issuer2340=== CONT TestCacheConfigHandler/no_signing_keys2341=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2342--- PASS: TestResolveDBConnectionString (0.00s)2343 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2344 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2345 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2346 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2347 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2348=== CONT TestCacheConfigHandler/no_cache_url_configured2349--- PASS: TestCacheConfigHandler (0.00s)2350 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2351 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2352 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2353 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2354=== CONT TestClientErrorHandling/InvalidStorePath23552026/09/23 13:29:35 INFO Received complete push request method=POST path=/api/pushes/1/complete23562026/09/23 13:29:35 WARN Failed to register uploaded object key=9927hwnn1xbnln3bf7a08knhrkh4zqxx.narinfo error="server returned 404: 404 page not found\n"23572026/09/23 13:29:35 INFO Upload complete. (108ms)23582026-09-23 13:29:35.440 UTC [63431] ERROR: relation "goose_db_version" does not exist at character 3623592026-09-23 13:29:35.440 UTC [63431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23602026-09-23 13:29:35.446 UTC [63432] ERROR: relation "goose_db_version" does not exist at character 3623612026-09-23 13:29:35.446 UTC [63432] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23622026/09/23 13:29:35 INFO All 1 paths already cached2363=== NAME TestClientIntegration2364 client_integration_test.go:312: Retrieved narinfo from S3:2365 StorePath: /nix/var/nix/builds/nix-62986-3424006005/TestClientIntegration1053392831/002/store/9927hwnn1xbnln3bf7a08knhrkh4zqxx-test-file.txt2366 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2367 Compression: zstd2368 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12369 NarSize: 1522370 References: 2371 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12372 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2373 client_integration_test.go:313: Decompressed .ls content (64 bytes):2374 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2375 client_integration_test.go:316: Testing garbage collection...23762026-09-23 13:29:35.472 UTC [63435] ERROR: relation "goose_db_version" does not exist at character 3623772026-09-23 13:29:35.472 UTC [63435] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23782026/09/23 13:29:35 OK 20241026095416_initial_model.sql (11.97ms)23792026/09/23 13:29:35 OK 20251210153512_drop_unused_gin_index.sql (618.29µs)23802026/09/23 13:29:35 OK 20241026095416_initial_model.sql (18.18ms)23812026/09/23 13:29:35 OK 20251210153512_drop_unused_gin_index.sql (508.5µs)23822026/09/23 13:29:35 OK 20251218171726_add_pins.sql (2.63ms)23832026/09/23 13:29:35 OK 20251218171726_add_pins.sql (2.22ms)23842026/09/23 13:29:35 OK 20260628120000_add_object_size_and_stats.sql (1.81ms)23852026/09/23 13:29:35 OK 20260628120000_add_object_size_and_stats.sql (2.25ms)23862026/09/23 13:29:35 OK 20260905000000_add_claims.sql (2.32ms)23872026/09/23 13:29:35 OK 20260905000000_add_claims.sql (2.15ms)23882026/09/23 13:29:35 OK 20260920000000_drop_claims.sql (1.25ms)23892026/09/23 13:29:35 OK 20241026095416_initial_model.sql (7.3ms)23902026/09/23 13:29:35 OK 20251210153512_drop_unused_gin_index.sql (495.67µs)23912026/09/23 13:29:35 OK 20260920000000_drop_claims.sql (1.06ms)23922026/09/23 13:29:35 OK 20260923120000_add_pushes.sql (1.06ms)23932026/09/23 13:29:35 goose: successfully migrated database to version: 2026092312000023942026/09/23 13:29:35 OK 20260923120000_add_pushes.sql (748.13µs)23952026/09/23 13:29:35 goose: successfully migrated database to version: 2026092312000023962026/09/23 13:29:35 OK 20251218171726_add_pins.sql (1.12ms)23972026/09/23 13:29:35 OK 1_commit_pending_closure.sql (1.04ms)23982026/09/23 13:29:35 OK 2_object_stats_trigger.sql (251.83µs)23992026/09/23 13:29:35 OK 1_commit_pending_closure.sql (908.42µs)24002026/09/23 13:29:35 OK 3_commit_push.sql (204.42µs)24012026/09/23 13:29:35 goose: up to current file version: 324022026/09/23 13:29:35 OK 2_object_stats_trigger.sql (273.83µs)24032026/09/23 13:29:35 OK 3_commit_push.sql (217.21µs)24042026/09/23 13:29:35 goose: up to current file version: 324052026/09/23 13:29:35 OK 20260628120000_add_object_size_and_stats.sql (2.28ms)24062026/09/23 13:29:35 OK 20260905000000_add_claims.sql (1.55ms)24072026/09/23 13:29:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures24082026/09/23 13:29:35 INFO Garbage collection started24092026/09/23 13:29:35 INFO Aborted multipart uploads count=024102026/09/23 13:29:35 WARN Force mode enabled - objects will be deleted immediately without grace period24112026/09/23 13:29:35 OK 20260920000000_drop_claims.sql (19.81ms)24122026/09/23 13:29:35 OK 20260923120000_add_pushes.sql (1.03ms)24132026/09/23 13:29:35 goose: successfully migrated database to version: 2026092312000024142026/09/23 13:29:35 OK 1_commit_pending_closure.sql (740.5µs)24152026/09/23 13:29:35 OK 2_object_stats_trigger.sql (214.67µs)24162026/09/23 13:29:35 OK 3_commit_push.sql (185.04µs)24172026/09/23 13:29:35 goose: up to current file version: 324182026-09-23 13:29:35.581 UTC [63438] ERROR: relation "goose_db_version" does not exist at character 3624192026-09-23 13:29:35.581 UTC [63438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2420=== CONT TestClientErrorHandling/ServerNotAvailable2421--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)2422 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2423 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2424 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)2425=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2426=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2427=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2428=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2429=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2430=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2431=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2432=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2433=== CONT TestClientErrorHandling/InvalidAuthToken24342026/09/23 13:29:35 OK 20241026095416_initial_model.sql (84.72ms)24352026/09/23 13:29:35 OK 20251210153512_drop_unused_gin_index.sql (14.12ms)24362026/09/23 13:29:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=024372026/09/23 13:29:35 OK 20251218171726_add_pins.sql (9.97ms)24382026/09/23 13:29:35 INFO Vacuumed table table=pending_closures24392026/09/23 13:29:35 OK 20260628120000_add_object_size_and_stats.sql (63.23ms)24402026/09/23 13:29:35 INFO Vacuumed table table=pending_objects24412026/09/23 13:29:35 INFO Vacuumed table table=multipart_uploads24422026/09/23 13:29:35 INFO Vacuumed table table=closures24432026/09/23 13:29:35 INFO Vacuumed table table=objects24442026/09/23 13:29:35 OK 20260905000000_add_claims.sql (49.95ms)24452026/09/23 13:29:35 OK 20260920000000_drop_claims.sql (19.33ms)24462026/09/23 13:29:35 OK 20260923120000_add_pushes.sql (14.08ms)24472026/09/23 13:29:35 goose: successfully migrated database to version: 2026092312000024482026/09/23 13:29:35 OK 1_commit_pending_closure.sql (1.01ms)24492026/09/23 13:29:35 OK 2_object_stats_trigger.sql (221.46µs)24502026/09/23 13:29:35 OK 3_commit_push.sql (214.13µs)24512026/09/23 13:29:35 goose: up to current file version: 324522026/09/23 13:29:35 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24532026-09-23 13:29:35.882 UTC [63454] ERROR: relation "goose_db_version" does not exist at character 3624542026-09-23 13:29:35.882 UTC [63454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2455=== RUN TestService_RequireScope_OIDC/builder_may_write2456=== PAUSE TestService_RequireScope_OIDC/builder_may_write2457=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2458=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2459=== RUN TestService_RequireScope_OIDC/ops_may_admin2460=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2461=== RUN TestService_RequireScope_OIDC/ops_may_not_write2462=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2463=== RUN TestService_RequireScope_OIDC/reader_may_not_write2464=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2465=== RUN TestService_RequireScope_OIDC/static_token_may_admin2466=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2467=== RUN TestService_RequireScope_OIDC/static_token_may_write2468=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2469=== RUN TestService_RequireScope_OIDC/reader_may_read2470=== PAUSE TestService_RequireScope_OIDC/reader_may_read2471=== RUN TestService_RequireScope_OIDC/writer_implies_read2472=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2473=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2474=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2475=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2476=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected24772026/09/23 13:29:35 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]2478=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2479=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24802026/09/23 13:29:35 WARN Authentication failed token_preview=eyJhbGciOi...ofWV7YSBbw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2481=== CONT TestService_RequireScope_OIDC/builder_may_write2482=== CONT TestService_RequireScope_OIDC/static_token_may_admin2483=== CONT TestService_RequireScope_OIDC/reader_may_not_write2484=== CONT TestService_RequireScope_OIDC/ops_may_not_write2485=== CONT TestService_RequireScope_OIDC/ops_may_admin2486=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2487--- PASS: TestService_AuthMiddleware_OIDC (1.70s)2488 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2489 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2490 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2491 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2492=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2493=== CONT TestService_RequireScope_OIDC/static_token_may_write2494=== CONT TestService_RequireScope_OIDC/writer_implies_read2495=== CONT TestService_RequireScope_OIDC/reader_may_read2496--- PASS: TestService_RequireScope_OIDC (1.95s)2497 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2498 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2499 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2500 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2501 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2502 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2503 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2504 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2505 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2506 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)25072026/09/23 13:29:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.109901ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25082026/09/23 13:29:35 OK 20241026095416_initial_model.sql (54.2ms)25092026/09/23 13:29:35 OK 20251210153512_drop_unused_gin_index.sql (5.77ms)25102026/09/23 13:29:35 OK 20251218171726_add_pins.sql (5.05ms)25112026/09/23 13:29:36 OK 20260628120000_add_object_size_and_stats.sql (10.12ms)25122026/09/23 13:29:36 OK 20260905000000_add_claims.sql (16.44ms)25132026/09/23 13:29:36 OK 20260920000000_drop_claims.sql (16.32ms)25142026/09/23 13:29:36 OK 20260923120000_add_pushes.sql (1.57ms)25152026/09/23 13:29:36 goose: successfully migrated database to version: 2026092312000025162026/09/23 13:29:36 OK 1_commit_pending_closure.sql (1.2ms)25172026/09/23 13:29:36 OK 2_object_stats_trigger.sql (261.21µs)25182026/09/23 13:29:36 OK 3_commit_push.sql (239.75µs)25192026/09/23 13:29:36 goose: up to current file version: 32520--- PASS: TestService_ReadAuthMiddleware (1.76s)25212026-09-23 13:29:36.181 UTC [63455] ERROR: relation "goose_db_version" does not exist at character 3625222026-09-23 13:29:36.181 UTC [63455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25232026/09/23 13:29:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.723059ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2524--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.66s)25252026/09/23 13:29:36 OK 20241026095416_initial_model.sql (93.73ms)25262026/09/23 13:29:36 OK 20251210153512_drop_unused_gin_index.sql (3.83ms)25272026/09/23 13:29:36 OK 20251218171726_add_pins.sql (13.85ms)25282026/09/23 13:29:36 OK 20260628120000_add_object_size_and_stats.sql (15.6ms)25292026/09/23 13:29:36 OK 20260905000000_add_claims.sql (34.03ms)25302026/09/23 13:29:36 OK 20260920000000_drop_claims.sql (17.99ms)25312026/09/23 13:29:36 OK 20260923120000_add_pushes.sql (11.85ms)25322026/09/23 13:29:36 goose: successfully migrated database to version: 2026092312000025332026/09/23 13:29:36 OK 1_commit_pending_closure.sql (4.36ms)25342026/09/23 13:29:36 OK 2_object_stats_trigger.sql (773.54µs)25352026/09/23 13:29:36 OK 3_commit_push.sql (548.13µs)25362026/09/23 13:29:36 goose: up to current file version: 32537--- PASS: TestService_ReadScope_PublicByDefault (1.65s)25382026-09-23 13:29:36.617 UTC [63456] ERROR: relation "goose_db_version" does not exist at character 3625392026-09-23 13:29:36.617 UTC [63456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25402026/09/23 13:29:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.440531ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2541=== NAME TestOrphanedObjectsGCStressTest2542 orphaned_objects_gc_test.go:509: Stress test completed successfully:2543 orphaned_objects_gc_test.go:510: - Active objects preserved: 202544 orphaned_objects_gc_test.go:511: - Objects deleted: 2102545 orphaned_objects_gc_test.go:512: - Total GC'd: 2102546--- PASS: TestOrphanedObjectsGCStressTest (8.87s)25472026/09/23 13:29:36 OK 20241026095416_initial_model.sql (64.82ms)25482026/09/23 13:29:36 OK 20251210153512_drop_unused_gin_index.sql (854.21µs)25492026/09/23 13:29:36 OK 20251218171726_add_pins.sql (1.67ms)25502026/09/23 13:29:36 OK 20260628120000_add_object_size_and_stats.sql (1.8ms)25512026/09/23 13:29:36 OK 20260905000000_add_claims.sql (1.88ms)25522026/09/23 13:29:36 OK 20260920000000_drop_claims.sql (1.15ms)25532026/09/23 13:29:36 OK 20260923120000_add_pushes.sql (734.38µs)25542026/09/23 13:29:36 goose: successfully migrated database to version: 2026092312000025552026/09/23 13:29:36 OK 1_commit_pending_closure.sql (1.37ms)25562026/09/23 13:29:36 OK 2_object_stats_trigger.sql (326.17µs)25572026/09/23 13:29:36 OK 3_commit_push.sql (291.96µs)25582026/09/23 13:29:36 goose: up to current file version: 325592026/09/23 13:29:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02560=== NAME TestPinProtectsFromGC2561 client_integration_test.go:794: Pin successfully protected closure from garbage collection25622026/09/23 13:29:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2563--- PASS: TestPinProtectsFromGC (5.22s)25642026/09/23 13:29:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25652026/09/23 13:29:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.527456589s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25662026/09/23 13:29:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02567=== NAME TestClientIntegration2568 client_integration_test.go:323: Objects in database after GC:2569 client_integration_test.go:323: Successfully deleted all objects with GC --force2570--- PASS: TestClientIntegration (4.50s)25712026/09/23 13:29:38 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25722026/09/23 13:29:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.931544ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25732026/09/23 13:29:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.957124ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25742026/09/23 13:29:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=747.537553ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25752026/09/23 13:29:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.4735746s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25762026/09/23 13:29:41 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 127.0.0.1:19999: connect: connection refused"25772026/09/23 13:29:41 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25782026/09/23 13:29:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.220141ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25792026/09/23 13:29:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.017487ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25802026/09/23 13:29:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=830.585765ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25812026/09/23 13:29:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.66336996s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/23 13:29:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25832026/09/23 13:29:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.015163ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25842026/09/23 13:29:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=403.902841ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25852026/09/23 13:29:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=816.400513ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25862026/09/23 13:29:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.649692634s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2587--- PASS: TestClientErrorHandling (0.00s)2588 --- PASS: TestClientErrorHandling/InvalidStorePath (1.35s)2589 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.29s)2590 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.67s)2591PASS2592{"timestamp":"2026-09-23T13:29:48.321392Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58767","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}25932026-09-23 13:29:51.388 UTC [63033] LOG: received smart shutdown request25942026-09-23 13:29:51.390 UTC [63033] LOG: background worker "logical replication launcher" (PID 63043) exited with exit code 125952026-09-23 13:29:51.528 UTC [63038] LOG: shutting down25962026-09-23 13:29:51.537 UTC [63038] LOG: checkpoint starting: shutdown immediate25972026/09/23 13:29:58 ERROR failed to kill rustfs error="no such process"25982026-09-23 13:29:58.894 UTC [63038] LOG: checkpoint complete: wrote 12460 buffers (76.0%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=4.632 s, sync=2.396 s, total=7.366 s; sync files=21875, longest=0.013 s, average=0.001 s; distance=302637 kB, estimate=302637 kB; lsn=0/13F18568, redo lsn=0/13F1856825992026-09-23 13:29:58.985 UTC [63033] LOG: database system is shut down26002026/09/23 13:30:01 ERROR failed to kill rustfs error="no such process"2601Running OIDC tests...2602=== RUN TestAudienceForIssuer2603=== PAUSE TestAudienceForIssuer2604=== RUN TestGlobMatch2605=== PAUSE TestGlobMatch2606=== RUN TestValidateToken_ValidToken2607=== PAUSE TestValidateToken_ValidToken2608=== RUN TestValidateToken_WrongAudience2609=== PAUSE TestValidateToken_WrongAudience2610=== RUN TestValidateToken_Expired2611=== PAUSE TestValidateToken_Expired2612=== RUN TestValidateToken_BoundClaimsMismatch2613=== PAUSE TestValidateToken_BoundClaimsMismatch2614=== RUN TestValidateToken_BoundSubjectMismatch2615=== PAUSE TestValidateToken_BoundSubjectMismatch2616=== RUN TestValidateToken_MultipleProviders2617=== PAUSE TestValidateToken_MultipleProviders2618=== RUN TestValidateToken_NoMatchingProvider2619=== PAUSE TestValidateToken_NoMatchingProvider2620=== RUN TestValidateToken_KubernetesServiceAccount2621=== PAUSE TestValidateToken_KubernetesServiceAccount2622=== RUN TestNewValidator_KubernetesRequiresCA2623=== PAUSE TestNewValidator_KubernetesRequiresCA2624=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2625=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2626=== RUN TestPins_ReservedForMatchingRule2627=== PAUSE TestPins_ReservedForMatchingRule2628=== RUN TestPins_TopLevelShorthand2629=== PAUSE TestPins_TopLevelShorthand2630=== RUN TestPins_ConfigValidation2631=== PAUSE TestPins_ConfigValidation2632=== RUN TestScopes_LegacyProviderDefaultsToWrite2633=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2634=== RUN TestScopes_Rules2635=== PAUSE TestScopes_Rules2636=== RUN TestScopes_ConfigValidation2637=== PAUSE TestScopes_ConfigValidation2638=== CONT TestAudienceForIssuer2639=== CONT TestValidateToken_KubernetesServiceAccount2640--- PASS: TestAudienceForIssuer (0.00s)2641=== CONT TestValidateToken_NoMatchingProvider2642=== CONT TestPins_ConfigValidation2643=== CONT TestValidateToken_Expired2644=== CONT TestScopes_Rules2645=== CONT TestPins_ReservedForMatchingRule2646=== CONT TestPins_TopLevelShorthand2647=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2648=== CONT TestValidateToken_ValidToken2649--- PASS: TestPins_ConfigValidation (0.01s)2650=== CONT TestScopes_LegacyProviderDefaultsToWrite2651=== CONT TestValidateToken_WrongAudience26522026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59345/oidc2653--- PASS: TestValidateToken_ValidToken (0.02s)2654=== CONT TestScopes_ConfigValidation26552026/09/23 13:30:04 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232656--- PASS: TestScopes_ConfigValidation (0.00s)2657=== CONT TestNewValidator_KubernetesRequiresCA2658--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)2659=== CONT TestValidateToken_MultipleProviders26602026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59349/oidc2661--- PASS: TestPins_TopLevelShorthand (0.05s)2662=== CONT TestValidateToken_BoundSubjectMismatch26632026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59351/oidc2664--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2665=== CONT TestValidateToken_BoundClaimsMismatch26662026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59353/oidc2667--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)2668=== CONT TestGlobMatch2669=== RUN TestGlobMatch/foo_foo2670=== PAUSE TestGlobMatch/foo_foo2671=== RUN TestGlobMatch/foo_bar2672=== PAUSE TestGlobMatch/foo_bar2673=== RUN TestGlobMatch/*_2674=== PAUSE TestGlobMatch/*_2675=== RUN TestGlobMatch/*_anything2676=== PAUSE TestGlobMatch/*_anything2677=== RUN TestGlobMatch/foo*_foo2678=== PAUSE TestGlobMatch/foo*_foo2679=== RUN TestGlobMatch/foo*_foobar2680=== PAUSE TestGlobMatch/foo*_foobar2681=== RUN TestGlobMatch/foo*_bar2682=== PAUSE TestGlobMatch/foo*_bar2683=== RUN TestGlobMatch/*bar_bar2684=== PAUSE TestGlobMatch/*bar_bar2685=== RUN TestGlobMatch/*bar_foobar2686=== PAUSE TestGlobMatch/*bar_foobar2687=== RUN TestGlobMatch/*bar_foo2688=== PAUSE TestGlobMatch/*bar_foo2689=== RUN TestGlobMatch/foo*bar_foobar2690=== PAUSE TestGlobMatch/foo*bar_foobar2691=== RUN TestGlobMatch/foo*bar_foo123bar2692=== PAUSE TestGlobMatch/foo*bar_foo123bar2693=== RUN TestGlobMatch/foo*bar_foobarbaz2694=== PAUSE TestGlobMatch/foo*bar_foobarbaz2695=== RUN TestGlobMatch/*/*_foo/bar2696=== PAUSE TestGlobMatch/*/*_foo/bar2697=== RUN TestGlobMatch/*/*_foo2698=== PAUSE TestGlobMatch/*/*_foo2699=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2700=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2701=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02702=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02703=== RUN TestGlobMatch/refs/*/main_refs/heads/main2704=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2705=== RUN TestGlobMatch/fo?_foo2706=== PAUSE TestGlobMatch/fo?_foo2707=== RUN TestGlobMatch/fo?_fo2708=== PAUSE TestGlobMatch/fo?_fo2709=== RUN TestGlobMatch/fo?_fooo2710=== PAUSE TestGlobMatch/fo?_fooo2711=== RUN TestGlobMatch/?oo_foo2712=== PAUSE TestGlobMatch/?oo_foo2713=== RUN TestGlobMatch/?oo_boo2714=== PAUSE TestGlobMatch/?oo_boo2715=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2716=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2717=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2718=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2719=== CONT TestGlobMatch/foo_foo2720=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2721=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2722=== CONT TestGlobMatch/?oo_boo2723=== CONT TestGlobMatch/?oo_foo2724=== CONT TestGlobMatch/fo?_fooo2725=== CONT TestGlobMatch/fo?_fo2726=== CONT TestGlobMatch/fo?_foo2727=== CONT TestGlobMatch/refs/*/main_refs/heads/main2728=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02729=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2730=== CONT TestGlobMatch/*/*_foo2731=== CONT TestGlobMatch/*/*_foo/bar2732=== CONT TestGlobMatch/foo*bar_foobarbaz2733=== CONT TestGlobMatch/foo*bar_foo123bar2734=== CONT TestGlobMatch/foo*bar_foobar2735=== CONT TestGlobMatch/*bar_foo2736=== CONT TestGlobMatch/*bar_foobar2737=== CONT TestGlobMatch/*bar_bar2738=== CONT TestGlobMatch/foo*_bar2739=== CONT TestGlobMatch/foo*_foobar2740=== CONT TestGlobMatch/foo*_foo2741=== CONT TestGlobMatch/*_anything2742=== CONT TestGlobMatch/*_2743=== CONT TestGlobMatch/foo_bar2744--- PASS: TestGlobMatch (0.00s)2745 --- PASS: TestGlobMatch/foo_foo (0.00s)2746 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2747 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2748 --- PASS: TestGlobMatch/?oo_boo (0.00s)2749 --- PASS: TestGlobMatch/?oo_foo (0.00s)2750 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2751 --- PASS: TestGlobMatch/fo?_fo (0.00s)2752 --- PASS: TestGlobMatch/fo?_foo (0.00s)2753 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2754 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2755 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2756 --- PASS: TestGlobMatch/*/*_foo (0.00s)2757 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2758 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2759 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2760 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2761 --- PASS: TestGlobMatch/*bar_foo (0.00s)2762 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2763 --- PASS: TestGlobMatch/*bar_bar (0.00s)2764 --- PASS: TestGlobMatch/foo*_bar (0.00s)2765 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2766 --- PASS: TestGlobMatch/foo*_foo (0.00s)2767 --- PASS: TestGlobMatch/*_anything (0.00s)2768 --- PASS: TestGlobMatch/*_ (0.00s)2769 --- PASS: TestGlobMatch/foo_bar (0.00s)27702026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59355/oidc2771--- PASS: TestValidateToken_WrongAudience (0.08s)27722026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59357/oidc2773--- PASS: TestScopes_Rules (0.09s)27742026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59360/oidc2775--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)27762026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59362/oidc2777--- PASS: TestValidateToken_Expired (0.10s)27782026/09/23 13:30:04 http: TLS handshake error from 127.0.0.1:59365: remote error: tls: bad certificate2779--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)27802026/09/23 13:30:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:593662781--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)27822026/09/23 13:30:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59368/oidc2783--- PASS: TestPins_ReservedForMatchingRule (0.13s)27842026/09/23 13:30:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59359/oidc2785--- PASS: TestValidateToken_NoMatchingProvider (0.16s)27862026/09/23 13:30:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59370/oidc27872026/09/23 13:30:04 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59373/oidc2788--- PASS: TestValidateToken_MultipleProviders (0.21s)2789PASS2790Running hook tests...2791=== RUN TestSendPathsEmpty2792=== PAUSE TestSendPathsEmpty2793=== RUN TestQueueEnqueueAndFetch2794=== PAUSE TestQueueEnqueueAndFetch2795=== RUN TestQueueDeduplication2796=== PAUSE TestQueueDeduplication2797=== RUN TestQueueRemove2798=== PAUSE TestQueueRemove2799=== RUN TestQueueFetchBatchLimit2800=== PAUSE TestQueueFetchBatchLimit2801=== RUN TestQueueRetryMovesToBack2802=== PAUSE TestQueueRetryMovesToBack2803=== RUN TestQueueFetchRemoveLifecycle2804=== PAUSE TestQueueFetchRemoveLifecycle2805=== RUN TestQueueConcurrentWriters2806=== PAUSE TestQueueConcurrentWriters2807=== RUN TestQueueRemoveLargeClosure2808=== PAUSE TestQueueRemoveLargeClosure2809=== RUN TestServerClientIntegration2810=== PAUSE TestServerClientIntegration2811=== RUN TestServerQueueError2812=== PAUSE TestServerQueueError2813=== RUN TestGetListenerSocketActivation2814 server_test.go:210: === RUN TestGetListenerSocketActivation2815 --- PASS: TestGetListenerSocketActivation (0.00s)2816 PASS2817 2818--- PASS: TestGetListenerSocketActivation (0.01s)2819=== RUN TestDrainIsolatesPoisonPath2820=== PAUSE TestDrainIsolatesPoisonPath2821=== RUN TestRunNotBlockedByPoisonHead2822=== PAUSE TestRunNotBlockedByPoisonHead2823=== RUN TestDrainGivesUpWhenServerDown2824=== PAUSE TestDrainGivesUpWhenServerDown2825=== RUN TestFailedPathPrunedByLaterClosure2826=== PAUSE TestFailedPathPrunedByLaterClosure2827=== RUN TestWorkerUploadsAndRemoves2828=== PAUSE TestWorkerUploadsAndRemoves2829=== RUN TestWorkerSkipsGCdPaths2830=== PAUSE TestWorkerSkipsGCdPaths2831=== RUN TestWorkerPrunesClosureDeps2832=== PAUSE TestWorkerPrunesClosureDeps2833=== RUN TestDrainTimeout2834=== PAUSE TestDrainTimeout2835=== CONT TestSendPathsEmpty2836=== CONT TestServerQueueError2837--- PASS: TestSendPathsEmpty (0.00s)2838=== CONT TestQueueFetchBatchLimit2839=== CONT TestQueueRetryMovesToBack2840=== CONT TestQueueDeduplication2841=== CONT TestQueueRemoveLargeClosure2842=== CONT TestWorkerUploadsAndRemoves2843=== CONT TestDrainTimeout2844=== CONT TestWorkerPrunesClosureDeps2845=== CONT TestWorkerSkipsGCdPaths2846=== CONT TestDrainGivesUpWhenServerDown28472026/09/23 13:30:04 ERROR Failed to queue paths error="permission denied" count=12848--- PASS: TestServerQueueError (0.00s)2849=== CONT TestFailedPathPrunedByLaterClosure28502026/09/23 13:30:04 INFO Upload queue status pending=228512026/09/23 13:30:04 INFO Uploading batch count=128522026/09/23 13:30:04 INFO Uploading batch count=128532026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=128542026/09/23 13:30:04 INFO Upload queue status pending=228552026/09/23 13:30:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-62986-3424006005/TestWorkerSkipsGCdPaths937954081/002/nonexistent28562026/09/23 13:30:04 INFO Uploading batch count=228572026/09/23 13:30:04 INFO Uploading batch count=128582026/09/23 13:30:04 INFO Upload queue status pending=22859--- PASS: TestQueueFetchBatchLimit (0.01s)2860=== CONT TestServerClientIntegration2861--- PASS: TestQueueDeduplication (0.01s)2862=== CONT TestRunNotBlockedByPoisonHead28632026/09/23 13:30:04 INFO Uploading batch count=228642026/09/23 13:30:04 INFO Uploading batch count=128652026/09/23 13:30:04 INFO Uploading batch count=228662026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=228672026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainGivesUpWhenServerDown1906990348/002/a28682026/09/23 13:30:04 INFO Uploading batch count=128692026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainGivesUpWhenServerDown1906990348/002/b28702026/09/23 13:30:04 INFO Uploading batch count=228712026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=228722026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainGivesUpWhenServerDown1906990348/002/c2873--- PASS: TestQueueRetryMovesToBack (0.01s)2874=== CONT TestQueueConcurrentWriters2875--- PASS: TestServerClientIntegration (0.00s)2876=== CONT TestQueueEnqueueAndFetch28772026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainGivesUpWhenServerDown1906990348/002/d28782026/09/23 13:30:04 INFO Uploading batch count=228792026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=228802026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainGivesUpWhenServerDown1906990348/002/e2881--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2882=== CONT TestDrainIsolatesPoisonPath28832026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainGivesUpWhenServerDown1906990348/002/f2884--- PASS: TestWorkerSkipsGCdPaths (0.01s)2885=== CONT TestQueueFetchRemoveLifecycle28862026/09/23 13:30:04 ERROR Drain finished with paths left in queue remaining=1028872026/09/23 13:30:04 INFO Upload queue status pending=328882026/09/23 13:30:04 INFO Uploading batch count=128892026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=12890--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2891=== CONT TestQueueRemove2892--- PASS: TestQueueEnqueueAndFetch (0.00s)28932026/09/23 13:30:04 INFO Uploading batch count=428942026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=42895--- PASS: TestQueueFetchRemoveLifecycle (0.00s)28962026/09/23 13:30:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62986-3424006005/TestDrainIsolatesPoisonPath2742762696/002/bbb28972026/09/23 13:30:04 INFO Uploading batch count=128982026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=128992026/09/23 13:30:04 INFO Uploading batch count=129002026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=129012026/09/23 13:30:04 INFO Uploading batch count=129022026/09/23 13:30:04 ERROR Upload failed error="upload failed" count=129032026/09/23 13:30:04 ERROR Drain finished with paths left in queue remaining=12904--- PASS: TestQueueRemove (0.00s)2905--- PASS: TestDrainIsolatesPoisonPath (0.01s)2906--- PASS: TestWorkerPrunesClosureDeps (0.03s)2907--- PASS: TestWorkerUploadsAndRemoves (0.03s)2908--- PASS: TestQueueRemoveLargeClosure (0.06s)2909--- PASS: TestQueueConcurrentWriters (0.14s)29102026/09/23 13:30:04 ERROR Upload failed error="context deadline exceeded" count=229112026/09/23 13:30:04 ERROR Drain finished with paths left in queue remaining=42912--- PASS: TestDrainTimeout (0.21s)29132026/09/23 13:30:05 INFO Uploading batch count=129142026/09/23 13:30:05 INFO Uploading batch count=129152026/09/23 13:30:05 INFO Uploading batch count=129162026/09/23 13:30:05 ERROR Upload failed error="upload failed" count=129172026/09/23 13:30:05 INFO Uploading batch count=129182026/09/23 13:30:05 ERROR Upload failed error="upload failed" count=129192026/09/23 13:30:05 INFO Uploading batch count=129202026/09/23 13:30:05 ERROR Upload failed error="upload failed" count=129212026/09/23 13:30:05 INFO Uploading batch count=129222026/09/23 13:30:05 ERROR Upload failed error="upload failed" count=129232026/09/23 13:30:05 ERROR Drain finished with paths left in queue remaining=12924--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2925PASS