niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #284
· 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.24s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestSetClientTLSErrors98--- PASS: TestEncodeNixBase32WithRealHash (0.00s)99=== CONT TestSetClientTLSDoesNotMutateDefaultTransport100--- PASS: TestShellSplit (0.00s)101=== CONT TestSetClientTLS102=== CONT TestUploadMultipart_SupersededByPeer103=== RUN TestUploadMultipart_SupersededByPeer/exists104=== PAUSE TestUploadMultipart_SupersededByPeer/exists105=== RUN TestUploadMultipart_SupersededByPeer/missing106=== PAUSE TestUploadMultipart_SupersededByPeer/missing107=== CONT TestClientSignaturesByStorePath108--- PASS: TestClientSignaturesByStorePath (0.00s)109=== CONT TestStreamPushReportsSignatures110=== CONT TestEncodeNixBase32111=== RUN TestEncodeNixBase32/test_string_hash112=== PAUSE TestEncodeNixBase32/test_string_hash113=== RUN TestEncodeNixBase32/empty_input114=== PAUSE TestEncodeNixBase32/empty_input115=== CONT TestDumpPathWriterError116=== CONT TestScriptTokenCachesUntilRefresh117=== CONT TestDumpPathSingleFile118=== CONT TestDumpPathMatchesNix119=== CONT TestStreamPushRequestLine120=== RUN TestSetClientTLSErrors/missing_cert_file121=== PAUSE TestSetClientTLSErrors/missing_cert_file1222026/10/01 07:34:27 ERROR Upload failed error=boom count=1123=== RUN TestSetClientTLSErrors/missing_key_file1242026/10/01 07:34:27 ERROR Upload failed error=boom count=1125=== PAUSE TestSetClientTLSErrors/missing_key_file126--- PASS: TestStreamPushReportsSignatures (0.00s)127=== RUN TestSetClientTLSErrors/missing_ca_file128=== PAUSE TestSetClientTLSErrors/missing_ca_file129=== RUN TestSetClientTLSErrors/invalid_ca_file130=== CONT TestScriptTokenEmptyCommand131=== PAUSE TestSetClientTLSErrors/invalid_ca_file132--- PASS: TestScriptTokenEmptyCommand (0.00s)133=== CONT TestScriptTokenBadJSON134=== CONT TestScriptTokenScriptFails135--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)136=== CONT TestScriptTokenEmptyToken137=== RUN TestSetClientTLS/rejects_connection_without_client_cert138--- PASS: TestDoServerRequestAttachesToken (0.01s)139=== CONT TestPathInfoCACompatibility140=== RUN TestPathInfoCACompatibility/null_ca_field141=== PAUSE TestPathInfoCACompatibility/null_ca_field142=== RUN TestPathInfoCACompatibility/old_string_format_-_text143=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text144=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive145=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive146=== RUN TestPathInfoCACompatibility/new_structured_format_-_text147=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text148=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method149=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method150=== CONT TestDoWithRetry_BodyReplayedViaGetBody151=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert152=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA153=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA154=== RUN TestSetClientTLS/preserves_debug_logging_transport155=== PAUSE TestSetClientTLS/preserves_debug_logging_transport156=== CONT TestResolveStorePath157--- PASS: TestResolveStorePath (0.00s)158=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1592026/10/01 07:34:27 WARN Rate limiter enabled after throttle name=server-test rate=5160--- PASS: TestScriptTokenScriptFails (0.01s)161=== CONT TestRateLimiterFeedback162=== RUN TestRateLimiterFeedback/429_enables_limiter163=== PAUSE TestRateLimiterFeedback/429_enables_limiter164=== RUN TestRateLimiterFeedback/503_enables_limiter165=== PAUSE TestRateLimiterFeedback/503_enables_limiter166=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter167=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter168=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter169=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter170=== CONT TestStreamPushBatchesUnderLoad1712026/10/01 07:34:27 WARN Rate limiter enabled after throttle name=server-test rate=51722026/10/01 07:34:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:551911732026/10/01 07:34:27 WARN Rate limiter backed off name=server-test rate=51742026/10/01 07:34:27 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55191175--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)176=== CONT TestStreamPushGivesUpOnDeadServer1772026/10/01 07:34:27 ERROR Upload failed error="connection refused" count=201782026/10/01 07:34:27 ERROR Server seems unavailable, giving up on batch untried=17179--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)180=== CONT TestStreamPushIsolatesFailures1812026/10/01 07:34:27 ERROR Upload failed error="bad path" count=3182--- PASS: TestStreamPushIsolatesFailures (0.00s)183=== CONT TestStreamPushReportsEveryPath184--- PASS: TestStreamPushReportsEveryPath (0.00s)185=== CONT TestPathInfoHashCompatibility186=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon190=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI191=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI192=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512193=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512194=== CONT TestParsePathInfoJSONMultiplePaths195=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths196=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== CONT TestParsePathInfoJSON200=== RUN TestParsePathInfoJSON/Nix_format201=== PAUSE TestParsePathInfoJSON/Nix_format202=== RUN TestParsePathInfoJSON/Lix_format203=== PAUSE TestParsePathInfoJSON/Lix_format204=== RUN TestParsePathInfoJSON/empty_input205=== PAUSE TestParsePathInfoJSON/empty_input206=== RUN TestParsePathInfoJSON/whitespace_only207=== PAUSE TestParsePathInfoJSON/whitespace_only208=== RUN TestParsePathInfoJSON/invalid_JSON209=== PAUSE TestParsePathInfoJSON/invalid_JSON210=== CONT TestShellSplitErrors211--- PASS: TestShellSplitErrors (0.00s)212=== CONT TestGetStorePathHash213=== RUN TestGetStorePathHash/valid_store_path214=== PAUSE TestGetStorePathHash/valid_store_path215=== RUN TestGetStorePathHash/basename_without_hyphen_should_error216=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error217=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error220=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error221=== CONT TestFileTokenMissing222--- PASS: TestFileTokenMissing (0.00s)223=== CONT TestScriptTokenNoExpiryRerunsEveryCall224--- PASS: TestScriptTokenBadJSON (0.01s)225=== CONT TestFileTokenEmpty226--- PASS: TestFileTokenEmpty (0.00s)227=== CONT TestFileTokenReadsAndCaches228--- PASS: TestScriptTokenEmptyToken (0.01s)229=== CONT TestStaticToken230--- PASS: TestStaticToken (0.00s)231=== CONT TestConvertHashToNix32232=== RUN TestConvertHashToNix32/SRI_format_to_Nix32233=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32234=== RUN TestConvertHashToNix32/already_Nix32_format235=== PAUSE TestConvertHashToNix32/already_Nix32_format236=== RUN TestConvertHashToNix32/invalid_format237=== PAUSE TestConvertHashToNix32/invalid_format238--- PASS: TestFileTokenReadsAndCaches (0.00s)239=== CONT TestPartSizeForNAR240=== RUN TestPartSizeForNAR/zero_stays_at_minimum241=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum242=== RUN TestPartSizeForNAR/small_stays_at_minimum243=== PAUSE TestPartSizeForNAR/small_stays_at_minimum244=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum245=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum246=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts247=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts248=== RUN TestPartSizeForNAR/1_TiB249=== PAUSE TestPartSizeForNAR/1_TiB250=== RUN TestPartSizeForNAR/5_TiB_S3_max_object251=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object252=== RUN TestPartSizeForNAR/capped_at_5_GiB253=== PAUSE TestPartSizeForNAR/capped_at_5_GiB254=== CONT TestUploadMultipart_PartsInParallel255=== CONT TestFilterOversizedClosures256=== RUN TestFilterOversizedClosures/no_limit_keeps_everything257=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything258=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped259=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped260=== RUN TestFilterOversizedClosures/all_closures_skipped261=== PAUSE TestFilterOversizedClosures/all_closures_skipped262=== CONT TestCaseHackSuffix263--- PASS: TestStreamPushRequestLine (0.03s)264=== CONT TestRegisterUploadedObjectReusesConnections265--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)266=== CONT TestUploadMultipart_SupersededByPeer/exists267=== CONT TestUploadMultipart_SupersededByPeer/missing268--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)269 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)270 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)271=== CONT TestEncodeNixBase32/test_string_hash272=== CONT TestEncodeNixBase32/empty_input273--- PASS: TestEncodeNixBase32 (0.00s)274 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)275 --- PASS: TestEncodeNixBase32/empty_input (0.00s)276=== CONT TestSetClientTLSErrors/missing_cert_file277=== CONT TestSetClientTLSErrors/invalid_ca_file278=== CONT TestSetClientTLSErrors/missing_ca_file279=== CONT TestSetClientTLSErrors/missing_key_file280--- PASS: TestSetClientTLSErrors (0.00s)281 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)282 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)283 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)284 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)285=== CONT TestPathInfoCACompatibility/null_ca_field286=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method287=== CONT TestPathInfoCACompatibility/new_structured_format_-_text288=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive289=== CONT TestPathInfoCACompatibility/old_string_format_-_text290--- PASS: TestPathInfoCACompatibility (0.00s)291 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)292 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)293 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)295 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)296=== CONT TestSetClientTLS/rejects_connection_without_client_cert297--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)298=== CONT TestSetClientTLS/preserves_debug_logging_transport2992026/10/01 07:34:27 http: TLS handshake error from 127.0.0.1:55269: remote error: tls: bad certificate300=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA301=== CONT TestRateLimiterFeedback/429_enables_limiter3022026/10/01 07:34:27 WARN Rate limiter enabled after throttle name=server-test rate=53032026/10/01 07:34:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:552713042026/10/01 07:34:27 WARN Rate limiter backed off name=server-test rate=5305=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter306=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter307=== CONT TestRateLimiterFeedback/503_enables_limiter3082026/10/01 07:34:27 WARN Rate limiter enabled after throttle name=server-test rate=53092026/10/01 07:34:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:552783102026/10/01 07:34:27 WARN Rate limiter backed off name=server-test rate=5311--- PASS: TestRateLimiterFeedback (0.00s)312 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)313 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)314 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)315 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths318=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512319=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI320=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon321--- PASS: TestPathInfoHashCompatibility (0.00s)322 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)323 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)324 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)325 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)326=== CONT TestParsePathInfoJSON/Nix_format327=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths328=== CONT TestGetStorePathHash/valid_store_path329=== CONT TestParsePathInfoJSON/invalid_JSON330=== CONT TestParsePathInfoJSON/whitespace_only331=== CONT TestParsePathInfoJSON/Lix_format332--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)335=== CONT TestParsePathInfoJSON/empty_input336=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error337=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error338=== CONT TestGetStorePathHash/basename_without_hyphen_should_error339=== CONT TestConvertHashToNix32/SRI_format_to_Nix32340=== CONT TestConvertHashToNix32/invalid_format341=== CONT TestConvertHashToNix32/already_Nix32_format342=== CONT TestPartSizeForNAR/zero_stays_at_minimum343=== CONT TestPartSizeForNAR/capped_at_5_GiB344=== CONT TestPartSizeForNAR/1_TiB345=== CONT TestFilterOversizedClosures/no_limit_keeps_everything346=== CONT TestPartSizeForNAR/5_TiB_S3_max_object347=== CONT TestPartSizeForNAR/small_stays_at_minimum348=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum349--- PASS: TestParsePathInfoJSON (0.00s)350 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)351 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)352 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)353 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)354 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)355=== CONT TestFilterOversizedClosures/all_closures_skipped356--- PASS: TestGetStorePathHash (0.00s)357 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)360 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)361--- PASS: TestConvertHashToNix32 (0.00s)362 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)363 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)364 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)365=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts3662026/10/01 07:34:27 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=50367--- PASS: TestPartSizeForNAR (0.00s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)375=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3762026/10/01 07:34:27 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000377--- PASS: TestFilterOversizedClosures (0.00s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)381--- PASS: TestSetClientTLS (0.01s)382 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385--- PASS: TestDumpPathWriterError (0.07s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)387--- PASS: TestStreamPushBatchesUnderLoad (0.10s)388--- PASS: TestCaseHackSuffix (0.24s)389--- PASS: TestDumpPathMatchesNix (0.31s)390--- PASS: TestDumpPathSingleFile (0.44s)391--- PASS: TestUploadMultipart_PartsInParallel (0.64s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld13".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-37277-823233434/postgres3904391127/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-37277-823233434/postgres3904391127/data -l logfile start421422/nix/var/nix/builds/nix-37277-823233434/postgres3904391127:5432 - no response4232026-10-01 07:34:31.401 UTC [38118] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 07:34:31.401 UTC [38118] LOG: listening on Unix socket "/nix/var/nix/builds/nix-37277-823233434/postgres3904391127/.s.PGSQL.5432"4252026-10-01 07:34:31.404 UTC [38126] LOG: database system was shut down at 2026-10-01 07:34:31 UTC4262026-10-01 07:34:31.406 UTC [38118] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-37277-823233434/postgres3904391127:5432 - accepting connections428{"timestamp":"2026-10-01T07:34:31.627295Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"79d5a3d7-b32a-4a56-ac28-9660e9cbf224","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}429{"timestamp":"2026-10-01T07:34:31.729587Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6f14c787-1fae-4289-b8c2-7b65d58bc4e3","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 07:34:31.969 UTC [38177] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 07:34:31.969 UTC [38177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 07:34:31 OK 20241026095416_initial_model.sql (7.02ms)4742026/10/01 07:34:31 OK 20251210153512_drop_unused_gin_index.sql (930.17µs)4752026/10/01 07:34:31 OK 20251218171726_add_pins.sql (1.1ms)4762026/10/01 07:34:31 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)4772026/10/01 07:34:31 OK 20260905000000_add_claims.sql (2.92ms)4782026/10/01 07:34:31 OK 20260920000000_drop_claims.sql (5ms)4792026/10/01 07:34:31 OK 20260923120000_add_pushes.sql (1.32ms)4802026/10/01 07:34:31 goose: successfully migrated database to version: 202609231200004812026/10/01 07:34:31 OK 1_commit_pending_closure.sql (1.96ms)4822026/10/01 07:34:31 OK 2_object_stats_trigger.sql (537.83µs)4832026/10/01 07:34:31 OK 3_commit_push.sql (409.96µs)4842026/10/01 07:34:31 goose: up to current file version: 34852026/10/01 07:34:32 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 07:34:32 INFO lead: released remote=192.0.2.1:12344872026/10/01 07:34:32 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 07:34:32 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.89s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 07:34:32.780 UTC [38257] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 07:34:32.780 UTC [38257] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 07:34:32 OK 20241026095416_initial_model.sql (6.46ms)4962026/10/01 07:34:32 OK 20251210153512_drop_unused_gin_index.sql (916.21µs)4972026/10/01 07:34:32 OK 20251218171726_add_pins.sql (2.43ms)4982026/10/01 07:34:32 OK 20260628120000_add_object_size_and_stats.sql (2.59ms)4992026/10/01 07:34:32 OK 20260905000000_add_claims.sql (3.67ms)5002026/10/01 07:34:32 OK 20260920000000_drop_claims.sql (1.26ms)5012026/10/01 07:34:32 OK 20260923120000_add_pushes.sql (1.45ms)5022026/10/01 07:34:32 goose: successfully migrated database to version: 202609231200005032026/10/01 07:34:32 OK 1_commit_pending_closure.sql (2.18ms)5042026/10/01 07:34:32 OK 2_object_stats_trigger.sql (545.71µs)5052026/10/01 07:34:32 OK 3_commit_push.sql (458.42µs)5062026/10/01 07:34:32 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.20s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestGCTaskStore_StartNew527=== PAUSE TestGCTaskStore_StartNew528=== RUN TestGCTaskStore_DeduplicateSameParams529=== PAUSE TestGCTaskStore_DeduplicateSameParams530=== RUN TestGCTaskStore_ConflictDifferentParams531=== PAUSE TestGCTaskStore_ConflictDifferentParams532=== RUN TestGCTaskStore_GetEmpty533=== PAUSE TestGCTaskStore_GetEmpty534=== RUN TestGCTaskStore_GetReturnsLatest535=== PAUSE TestGCTaskStore_GetReturnsLatest536=== RUN TestGCTaskStore_CompletedAllowsNewTask537=== PAUSE TestGCTaskStore_CompletedAllowsNewTask538=== RUN TestGCTaskStore_PhaseUpdates539=== PAUSE TestGCTaskStore_PhaseUpdates540=== RUN TestGCTaskStore_Fail541=== PAUSE TestGCTaskStore_Fail542=== RUN TestGracefulShutdownDrainsInflight543=== PAUSE TestGracefulShutdownDrainsInflight544=== RUN TestService_healthCheckHandler545=== PAUSE TestService_healthCheckHandler546=== RUN TestService_readinessHandler547=== PAUSE TestService_readinessHandler548=== RUN TestGenerateLandingPage549=== PAUSE TestGenerateLandingPage550=== RUN TestCacheConfigHandlerMaxNarSize551=== PAUSE TestCacheConfigHandlerMaxNarSize552=== RUN TestCreatePendingClosureRejectsOversizedNAR553=== PAUSE TestCreatePendingClosureRejectsOversizedNAR554=== RUN TestNARDeduplicationMetadataUploadBug555=== PAUSE TestNARDeduplicationMetadataUploadBug556=== RUN TestMetricsInventory557=== PAUSE TestMetricsInventory558=== RUN TestService_NativeMTLS559=== PAUSE TestService_NativeMTLS560=== RUN TestServerTLSConfig561=== PAUSE TestServerTLSConfig562=== RUN TestMultipartCleanup563=== PAUSE TestMultipartCleanup564=== RUN TestObjectStatsTrigger565=== PAUSE TestObjectStatsTrigger566=== RUN TestOrphanedObjectsGC567=== PAUSE TestOrphanedObjectsGC568=== RUN TestOrphanedObjectsGCStressTest569=== PAUSE TestOrphanedObjectsGCStressTest570=== RUN TestCreatePin_ReservedPins571=== PAUSE TestCreatePin_ReservedPins572=== RUN TestParseSingleRange573=== PAUSE TestParseSingleRange574=== RUN TestProxyHeadersOnlyTrustedOnSocket575=== PAUSE TestProxyHeadersOnlyTrustedOnSocket576=== RUN TestIsValidCachePath577=== PAUSE TestIsValidCachePath578=== RUN TestReadProxyNarinfo579=== PAUSE TestReadProxyNarinfo580=== RUN TestReadProxyNarinfoAlreadyDecompressed581=== PAUSE TestReadProxyNarinfoAlreadyDecompressed582=== RUN TestReadProxyNarStreaming583=== PAUSE TestReadProxyNarStreaming584=== RUN TestReadProxy404585=== PAUSE TestReadProxy404586=== RUN TestReadProxyInvalidPath587=== PAUSE TestReadProxyInvalidPath588=== RUN TestReadProxyHead589=== PAUSE TestReadProxyHead590=== RUN TestReadProxyConditionalGet591=== PAUSE TestReadProxyConditionalGet592=== RUN TestReadProxyRootRedirectsToIndexHTML593=== PAUSE TestReadProxyRootRedirectsToIndexHTML594=== RUN TestReadProxyDisabled595=== PAUSE TestReadProxyDisabled596=== RUN TestReadRedirectNar597=== PAUSE TestReadRedirectNar598=== RUN TestReadRedirectKeepsNarinfoProxied599=== PAUSE TestReadRedirectKeepsNarinfoProxied600=== RUN TestReadProxyRangeRequest601=== PAUSE TestReadProxyRangeRequest602=== RUN TestReadRedirectUsesPublicS3URL603=== PAUSE TestReadRedirectUsesPublicS3URL604=== RUN TestPush_OverlappingRootsStoreOneRowPerKey605=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey606=== RUN TestPush_CompleteCommitsEveryRoot607=== PAUSE TestPush_CompleteCommitsEveryRoot608=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit609=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit610=== RUN TestPush_RejectsBadRequests611=== PAUSE TestPush_RejectsBadRequests612=== RUN TestPush_SignsNarinfosOfItsPendingObjects613=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects614=== RUN TestRedundantMultipartUpload615=== PAUSE TestRedundantMultipartUpload616=== RUN TestCompleteMultipartUpload_ErrorButObjectExists617=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists618=== RUN TestCompletedNarNotReofferedAcrossClosures619=== PAUSE TestCompletedNarNotReofferedAcrossClosures620=== RUN TestPresignedUploadRegisteredBeforeCommit621=== PAUSE TestPresignedUploadRegisteredBeforeCommit622=== RUN TestService_Rustfstest623=== PAUSE TestService_Rustfstest624=== RUN TestParseSize625=== PAUSE TestParseSize626=== RUN TestSkippedUploadsHandler627=== PAUSE TestSkippedUploadsHandler628=== RUN TestSystemdListenerNotActivated629--- PASS: TestSystemdListenerNotActivated (0.00s)630=== RUN TestWatchdogBeatsWhenHealthy631--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)632=== RUN TestWatchdogSkipsWhenUnhealthy6332026/10/01 07:34:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6342026/10/01 07:34:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:34:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"642--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)643=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle644=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle645=== RUN TestProxyWriteTimeout646=== PAUSE TestProxyWriteTimeout647=== RUN TestIsValidUploadKey648=== PAUSE TestIsValidUploadKey649=== RUN TestUploadHandlersRejectInvalidKeys650=== PAUSE TestUploadHandlersRejectInvalidKeys651=== RUN TestUploadHandlersRejectOversizedBody652=== PAUSE TestUploadHandlersRejectOversizedBody653=== RUN TestService_cleanupPendingClosuresHandler654=== PAUSE TestService_cleanupPendingClosuresHandler655=== RUN TestService_createPendingClosureHandler656=== PAUSE TestService_createPendingClosureHandler657=== RUN TestService_verifyS3Integrity658=== PAUSE TestService_verifyS3Integrity659=== RUN TestCompleteMultipartUnregistered660=== PAUSE TestCompleteMultipartUnregistered661=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT662=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT663=== CONT TestMultipartCleanup664=== CONT TestService_AuthMiddleware665=== CONT TestServerTLSConfig666=== RUN TestServerTLSConfig/no_client_CA667=== PAUSE TestServerTLSConfig/no_client_CA668=== RUN TestServerTLSConfig/missing_CA_file669=== PAUSE TestServerTLSConfig/missing_CA_file670=== RUN TestServerTLSConfig/not_a_PEM_file671=== PAUSE TestServerTLSConfig/not_a_PEM_file672=== CONT TestServerTLSConfig/no_client_CA673=== CONT TestService_NativeMTLS674=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT675=== CONT TestMetricsInventory676=== CONT TestCompleteMultipartUnregistered677=== CONT TestNARDeduplicationMetadataUploadBug678=== CONT TestGCTaskStore_GetEmpty679--- PASS: TestGCTaskStore_GetEmpty (0.00s)680=== CONT TestCreatePendingClosureRejectsOversizedNAR681=== CONT TestClientMultipleUploads682=== CONT TestDeduplicatedObjectsRecordedAsPending6832026/10/01 07:34:33 INFO Received uploads request method=POST path=/api/pending_closures684--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)685=== CONT TestGCTaskStore_ConflictDifferentParams686--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)687=== CONT TestGCTaskStore_DeduplicateSameParams688--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)689=== CONT TestGCTaskStore_StartNew690--- PASS: TestGCTaskStore_StartNew (0.00s)691=== CONT TestFailedS3DeleteKeepsTombstone6922026-10-01 07:34:33.373 UTC [38333] ERROR: relation "goose_db_version" does not exist at character 366932026-10-01 07:34:33.373 UTC [38333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6942026/10/01 07:34:33 OK 20241026095416_initial_model.sql (14.12ms)6952026-10-01 07:34:33.399 UTC [38335] ERROR: relation "goose_db_version" does not exist at character 366962026-10-01 07:34:33.399 UTC [38335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6972026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)6982026/10/01 07:34:33 OK 20251218171726_add_pins.sql (3.39ms)6992026-10-01 07:34:33.406 UTC [38336] ERROR: relation "goose_db_version" does not exist at character 367002026-10-01 07:34:33.406 UTC [38336] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7012026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)7022026/10/01 07:34:33 OK 20260905000000_add_claims.sql (2.84ms)7032026-10-01 07:34:33.410 UTC [38337] ERROR: relation "goose_db_version" does not exist at character 367042026-10-01 07:34:33.410 UTC [38337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7052026-10-01 07:34:33.411 UTC [38338] ERROR: relation "goose_db_version" does not exist at character 367062026-10-01 07:34:33.411 UTC [38338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (2.56ms)7082026-10-01 07:34:33.414 UTC [38339] ERROR: relation "goose_db_version" does not exist at character 367092026-10-01 07:34:33.414 UTC [38339] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7102026-10-01 07:34:33.414 UTC [38340] ERROR: relation "goose_db_version" does not exist at character 367112026-10-01 07:34:33.414 UTC [38340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026-10-01 07:34:33.414 UTC [38341] ERROR: relation "goose_db_version" does not exist at character 367132026-10-01 07:34:33.414 UTC [38341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026/10/01 07:34:33 OK 20241026095416_initial_model.sql (7.97ms)7152026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (2.07ms)7162026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007172026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (970.5µs)7182026-10-01 07:34:33.416 UTC [38343] ERROR: relation "goose_db_version" does not exist at character 367192026-10-01 07:34:33.416 UTC [38343] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026/10/01 07:34:33 OK 1_commit_pending_closure.sql (2.04ms)7212026-10-01 07:34:33.417 UTC [38342] ERROR: relation "goose_db_version" does not exist at character 367222026-10-01 07:34:33.417 UTC [38342] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026/10/01 07:34:33 OK 2_object_stats_trigger.sql (493.5µs)7242026/10/01 07:34:33 OK 3_commit_push.sql (415.58µs)7252026/10/01 07:34:33 goose: up to current file version: 37262026/10/01 07:34:33 OK 20251218171726_add_pins.sql (2.43ms)7272026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (2.11ms)7282026/10/01 07:34:33 OK 20241026095416_initial_model.sql (8.66ms)7292026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)7302026/10/01 07:34:33 OK 20260905000000_add_claims.sql (1.98ms)7312026/10/01 07:34:33 OK 20241026095416_initial_model.sql (7.42ms)7322026/10/01 07:34:33 OK 20241026095416_initial_model.sql (5.88ms)7332026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (7.98ms)7342026/10/01 07:34:33 OK 20241026095416_initial_model.sql (15.57ms)7352026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (9.1ms)7362026/10/01 07:34:33 OK 20251218171726_add_pins.sql (9.52ms)7372026/10/01 07:34:33 OK 20241026095416_initial_model.sql (13.3ms)7382026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (70.26ms)7392026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (64.51ms)7402026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (64.33ms)7412026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (64.87ms)7422026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007432026/10/01 07:34:33 OK 1_commit_pending_closure.sql (2.13ms)7442026/10/01 07:34:33 OK 2_object_stats_trigger.sql (1.38ms)7452026/10/01 07:34:33 OK 3_commit_push.sql (450.83µs)7462026/10/01 07:34:33 goose: up to current file version: 37472026/10/01 07:34:33 OK 20251218171726_add_pins.sql (73.3ms)7482026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (72.45ms)7492026/10/01 07:34:33 OK 20251218171726_add_pins.sql (16.08ms)7502026/10/01 07:34:33 OK 20241026095416_initial_model.sql (93.86ms)7512026/10/01 07:34:33 OK 20251218171726_add_pins.sql (19.72ms)7522026/10/01 07:34:33 OK 20260905000000_add_claims.sql (10ms)7532026/10/01 07:34:33 OK 20241026095416_initial_model.sql (92.97ms)7542026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)7552026/10/01 07:34:33 OK 20251218171726_add_pins.sql (19.78ms)7562026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (8.73ms)7572026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (9.82ms)7582026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (20.13ms)7592026/10/01 07:34:33 OK 20241026095416_initial_model.sql (102.56ms)7602026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (12.89ms)7612026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (11.16ms)7622026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (9.15ms)7632026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (1.32ms)7642026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007652026/10/01 07:34:33 OK 20251218171726_add_pins.sql (10.44ms)7662026/10/01 07:34:33 OK 20251218171726_add_pins.sql (2.56ms)7672026/10/01 07:34:33 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)7682026/10/01 07:34:33 OK 20260905000000_add_claims.sql (2.83ms)7692026/10/01 07:34:33 OK 1_commit_pending_closure.sql (2.26ms)7702026/10/01 07:34:33 OK 20260905000000_add_claims.sql (2.74ms)7712026/10/01 07:34:33 OK 20260905000000_add_claims.sql (2.8ms)7722026/10/01 07:34:33 OK 20251218171726_add_pins.sql (2.02ms)7732026/10/01 07:34:33 OK 2_object_stats_trigger.sql (580.33µs)7742026/10/01 07:34:33 OK 3_commit_push.sql (380.71µs)7752026/10/01 07:34:33 goose: up to current file version: 37762026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)7772026/10/01 07:34:33 OK 20260905000000_add_claims.sql (5.3ms)7782026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)7792026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (8.87ms)7802026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (9.13ms)7812026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (9.12ms)7822026/10/01 07:34:33 OK 20260628120000_add_object_size_and_stats.sql (15.2ms)7832026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (12.78ms)7842026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (6.5ms)7852026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007862026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (6.62ms)7872026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007882026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (7.59ms)7892026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007902026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (1.62ms)7912026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200007922026/10/01 07:34:33 OK 20260905000000_add_claims.sql (14.48ms)7932026/10/01 07:34:33 OK 20260905000000_add_claims.sql (14.59ms)7942026/10/01 07:34:33 OK 1_commit_pending_closure.sql (1.59ms)7952026/10/01 07:34:33 OK 1_commit_pending_closure.sql (1.8ms)7962026/10/01 07:34:33 OK 2_object_stats_trigger.sql (523.21µs)7972026/10/01 07:34:33 OK 2_object_stats_trigger.sql (494.13µs)7982026/10/01 07:34:33 OK 1_commit_pending_closure.sql (2.27ms)7992026/10/01 07:34:33 OK 3_commit_push.sql (400.17µs)8002026/10/01 07:34:33 goose: up to current file version: 38012026/10/01 07:34:33 OK 3_commit_push.sql (476.83µs)8022026/10/01 07:34:33 goose: up to current file version: 38032026/10/01 07:34:33 OK 2_object_stats_trigger.sql (541.75µs)8042026/10/01 07:34:33 OK 1_commit_pending_closure.sql (1.91ms)8052026/10/01 07:34:33 OK 3_commit_push.sql (402.88µs)8062026/10/01 07:34:33 goose: up to current file version: 38072026/10/01 07:34:33 OK 2_object_stats_trigger.sql (516.29µs)8082026/10/01 07:34:33 OK 3_commit_push.sql (362.75µs)8092026/10/01 07:34:33 goose: up to current file version: 38102026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (13.04ms)8112026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (13.05ms)8122026/10/01 07:34:33 OK 20260905000000_add_claims.sql (15.12ms)8132026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (1.29ms)8142026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200008152026/10/01 07:34:33 OK 1_commit_pending_closure.sql (1.88ms)8162026/10/01 07:34:33 OK 2_object_stats_trigger.sql (528.92µs)8172026/10/01 07:34:33 OK 3_commit_push.sql (416.92µs)8182026/10/01 07:34:33 goose: up to current file version: 38192026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (8.96ms)8202026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200008212026/10/01 07:34:33 OK 20260920000000_drop_claims.sql (8.82ms)8222026/10/01 07:34:33 OK 1_commit_pending_closure.sql (2.42ms)8232026/10/01 07:34:33 OK 2_object_stats_trigger.sql (627.88µs)8242026/10/01 07:34:33 OK 3_commit_push.sql (399.5µs)8252026/10/01 07:34:33 goose: up to current file version: 38262026/10/01 07:34:33 OK 20260923120000_add_pushes.sql (8.14ms)8272026/10/01 07:34:33 goose: successfully migrated database to version: 202609231200008282026/10/01 07:34:33 OK 1_commit_pending_closure.sql (2.05ms)8292026/10/01 07:34:33 OK 2_object_stats_trigger.sql (534.63µs)8302026/10/01 07:34:33 OK 3_commit_push.sql (409.04µs)8312026/10/01 07:34:33 goose: up to current file version: 38322026/10/01 07:34:33 INFO Received uploads request method=POST path=/api/pending_closures833--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.47s)834=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8352026/10/01 07:34:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8362026/10/01 07:34:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"837--- PASS: TestService_NativeMTLS (0.58s)838=== CONT TestGCSweepDeliversEachKeyOnce8392026/10/01 07:34:33 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"840--- PASS: TestService_AuthMiddleware (0.74s)841=== CONT TestTombstonedObjectOfferedWithoutWaiting8422026-10-01 07:34:34.053 UTC [38373] ERROR: relation "goose_db_version" does not exist at character 368432026-10-01 07:34:34.053 UTC [38373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8442026-10-01 07:34:34.085 UTC [38376] ERROR: relation "goose_db_version" does not exist at character 368452026-10-01 07:34:34.085 UTC [38376] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8462026-10-01 07:34:34.087 UTC [38375] ERROR: relation "goose_db_version" does not exist at character 368472026-10-01 07:34:34.087 UTC [38375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026/10/01 07:34:34 OK 20241026095416_initial_model.sql (20.54ms)8492026/10/01 07:34:34 OK 20241026095416_initial_model.sql (15.97ms)8502026/10/01 07:34:34 OK 20241026095416_initial_model.sql (49.13ms)8512026/10/01 07:34:34 OK 20251210153512_drop_unused_gin_index.sql (12.19ms)8522026/10/01 07:34:34 OK 20251210153512_drop_unused_gin_index.sql (23.66ms)8532026/10/01 07:34:34 OK 20251210153512_drop_unused_gin_index.sql (27.89ms)8542026/10/01 07:34:34 OK 20251218171726_add_pins.sql (24.59ms)8552026/10/01 07:34:34 OK 20251218171726_add_pins.sql (31.66ms)8562026/10/01 07:34:34 OK 20260628120000_add_object_size_and_stats.sql (26.61ms)8572026/10/01 07:34:34 OK 20251218171726_add_pins.sql (34.58ms)8582026/10/01 07:34:34 OK 20260905000000_add_claims.sql (40.57ms)8592026/10/01 07:34:34 OK 20260628120000_add_object_size_and_stats.sql (35.81ms)8602026/10/01 07:34:34 OK 20260628120000_add_object_size_and_stats.sql (42.17ms)8612026/10/01 07:34:34 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/01 07:34:34 OK 20260920000000_drop_claims.sql (10.13ms)8632026/10/01 07:34:34 OK 20260905000000_add_claims.sql (9.11ms)8642026/10/01 07:34:34 OK 20260905000000_add_claims.sql (8.92ms)8652026/10/01 07:34:34 OK 20260923120000_add_pushes.sql (1.34ms)8662026/10/01 07:34:34 goose: successfully migrated database to version: 202609231200008672026/10/01 07:34:34 OK 1_commit_pending_closure.sql (1.97ms)8682026/10/01 07:34:34 OK 2_object_stats_trigger.sql (667.67µs)8692026/10/01 07:34:34 OK 3_commit_push.sql (570.54µs)8702026/10/01 07:34:34 goose: up to current file version: 38712026/10/01 07:34:34 OK 20260920000000_drop_claims.sql (26.27ms)8722026/10/01 07:34:34 OK 20260920000000_drop_claims.sql (26.32ms)8732026/10/01 07:34:34 OK 20260923120000_add_pushes.sql (2.88ms)8742026/10/01 07:34:34 goose: successfully migrated database to version: 202609231200008752026/10/01 07:34:34 OK 1_commit_pending_closure.sql (1.89ms)8762026/10/01 07:34:34 OK 2_object_stats_trigger.sql (657.92µs)8772026/10/01 07:34:34 OK 3_commit_push.sql (577µs)8782026/10/01 07:34:34 goose: up to current file version: 38792026/10/01 07:34:34 OK 20260923120000_add_pushes.sql (8.78ms)8802026/10/01 07:34:34 goose: successfully migrated database to version: 202609231200008812026/10/01 07:34:34 OK 1_commit_pending_closure.sql (1.98ms)8822026/10/01 07:34:34 OK 2_object_stats_trigger.sql (524.29µs)8832026/10/01 07:34:34 OK 3_commit_push.sql (417.67µs)8842026/10/01 07:34:34 goose: up to current file version: 3885--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.13s)886=== CONT TestGCSweepSkipsPendingObjects887=== NAME TestNARDeduplicationMetadataUploadBug888 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-37277-823233434/TestNARDeduplicationMetadataUploadBug274410256/001/store/p4lja1br2cj1wbhslbl4m9x21anfgngp-file1.txt8892026-10-01 07:34:34.556 UTC [38437] ERROR: relation "goose_db_version" does not exist at character 368902026-10-01 07:34:34.556 UTC [38437] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8912026/10/01 07:34:34 OK 20241026095416_initial_model.sql (18.34ms)8922026/10/01 07:34:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8932026/10/01 07:34:34 OK 20251210153512_drop_unused_gin_index.sql (9.22ms)8942026/10/01 07:34:34 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst895--- PASS: TestCompleteMultipartUnregistered (1.45s)896=== CONT TestServerTLSConfig/not_a_PEM_file897=== CONT TestServerTLSConfig/missing_CA_file898--- PASS: TestServerTLSConfig (0.00s)899 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)900 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)901 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)902=== CONT TestGCBugBareHashReferences9032026/10/01 07:34:34 OK 20251218171726_add_pins.sql (55.14ms)9042026/10/01 07:34:34 OK 20260628120000_add_object_size_and_stats.sql (2.45ms)9052026/10/01 07:34:34 OK 20260905000000_add_claims.sql (6.77ms)9062026/10/01 07:34:34 OK 20260920000000_drop_claims.sql (6.84ms)9072026/10/01 07:34:34 OK 20260923120000_add_pushes.sql (5.92ms)9082026/10/01 07:34:34 goose: successfully migrated database to version: 202609231200009092026/10/01 07:34:34 OK 1_commit_pending_closure.sql (1.98ms)9102026/10/01 07:34:34 INFO Received push request method=POST path=/api/pushes9112026/10/01 07:34:34 OK 2_object_stats_trigger.sql (575.25µs)9122026/10/01 07:34:34 OK 3_commit_push.sql (391.71µs)9132026/10/01 07:34:34 goose: up to current file version: 39142026/10/01 07:34:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9152026/10/01 07:34:34 INFO Uploading p4lja1br2cj1wbhslbl4m9x21anfgngp-file1.txt (160B)9162026/10/01 07:34:34 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9172026/10/01 07:34:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9182026/10/01 07:34:34 WARN Failed to register uploaded object key=p4lja1br2cj1wbhslbl4m9x21anfgngp.ls error="server returned 404: 404 page not found\n"9192026/10/01 07:34:34 INFO Signed narinfos id=1 count=19202026/10/01 07:34:34 INFO Uploading 1 narinfos9212026/10/01 07:34:34 INFO Received complete push request method=POST path=/api/pushes/1/complete9222026/10/01 07:34:34 WARN Failed to register uploaded object key=p4lja1br2cj1wbhslbl4m9x21anfgngp.narinfo error="server returned 404: 404 page not found\n"9232026/10/01 07:34:34 INFO Upload complete. (146ms)924=== NAME TestNARDeduplicationMetadataUploadBug925 metadata_upload_test.go:54: Retrieved narinfo from S3:926 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestNARDeduplicationMetadataUploadBug274410256/001/store/p4lja1br2cj1wbhslbl4m9x21anfgngp-file1.txt927 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst928 Compression: zstd929 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf930 NarSize: 160931 References: 932 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf933 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)934 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):935 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}936--- PASS: TestMetricsInventory (1.67s)937=== CONT TestPushDedupSurvivesConcurrentGC938=== NAME TestNARDeduplicationMetadataUploadBug939 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-37277-823233434/TestNARDeduplicationMetadataUploadBug274410256/001/store/yg0xkkdvzixb32kfm5v6h50m2shn23ph-file2.txt9402026/10/01 07:34:34 INFO Received push request method=POST path=/api/pushes9412026/10/01 07:34:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9422026/10/01 07:34:34 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/01 07:34:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9442026/10/01 07:34:34 INFO Signed narinfos id=2 count=19452026/10/01 07:34:34 WARN Failed to register uploaded object key=yg0xkkdvzixb32kfm5v6h50m2shn23ph.ls error="server returned 404: 404 page not found\n"9462026/10/01 07:34:34 INFO Uploading 1 narinfos9472026/10/01 07:34:34 INFO Received complete push request method=POST path=/api/pushes/2/complete9482026/10/01 07:34:34 WARN Failed to register uploaded object key=yg0xkkdvzixb32kfm5v6h50m2shn23ph.narinfo error="server returned 404: 404 page not found\n"9492026/10/01 07:34:34 INFO Upload complete. (90ms)950 metadata_upload_test.go:76: Retrieved narinfo from S3:951 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestNARDeduplicationMetadataUploadBug274410256/001/store/yg0xkkdvzixb32kfm5v6h50m2shn23ph-file2.txt952 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst953 Compression: zstd954 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf955 NarSize: 160956 References: 957 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf958 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)959 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):960 {"version":1,"root":{"type":"regular","size":44}}961--- PASS: TestNARDeduplicationMetadataUploadBug (1.86s)962=== CONT TestGCMetrics9632026/10/01 07:34:35 INFO Received cleanup request method=DELETE path=/api/pending_closures9642026/10/01 07:34:35 INFO Aborted multipart uploads count=1965--- PASS: TestMultipartCleanup (1.97s)966=== CONT TestLeadEndsOnShutdown9672026/10/01 07:34:35 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/01 07:34:35 INFO Aborted multipart uploads count=09692026/10/01 07:34:35 WARN Force mode enabled - objects will be deleted immediately without grace period9702026/10/01 07:34:35 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."9712026/10/01 07:34:35 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."972--- PASS: TestFailedS3DeleteKeepsTombstone (2.13s)973=== CONT TestService_ReadScope_PublicByDefault9742026-10-01 07:34:35.416 UTC [38525] ERROR: relation "goose_db_version" does not exist at character 369752026-10-01 07:34:35.416 UTC [38525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9762026-10-01 07:34:35.444 UTC [38526] ERROR: relation "goose_db_version" does not exist at character 369772026-10-01 07:34:35.444 UTC [38526] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC978=== NAME TestClientMultipleUploads979 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-37277-823233434/TestClientMultipleUploads10913960/001/store/4nz74b21l88p90w3kj623imdgspzwp22-test-file-0.txt9802026/10/01 07:34:35 OK 20241026095416_initial_model.sql (58.35ms)9812026/10/01 07:34:35 OK 20251210153512_drop_unused_gin_index.sql (9.12ms)9822026/10/01 07:34:35 OK 20241026095416_initial_model.sql (54.92ms)983 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-37277-823233434/TestClientMultipleUploads10913960/001/store/cd1k279lg4n2djglydif64czamwaxbh5-test-file-1.txt9842026/10/01 07:34:35 OK 20251218171726_add_pins.sql (3.37ms)9852026/10/01 07:34:35 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)9862026/10/01 07:34:35 INFO Received uploads request method=POST path=/api/pending_closures987--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.66s)988=== CONT TestClientIntegration9892026/10/01 07:34:35 OK 20260628120000_add_object_size_and_stats.sql (36.23ms)9902026/10/01 07:34:35 OK 20251218171726_add_pins.sql (36.66ms)9912026/10/01 07:34:35 OK 20260905000000_add_claims.sql (14.74ms)9922026/10/01 07:34:35 OK 20260628120000_add_object_size_and_stats.sql (13.96ms)9932026/10/01 07:34:35 OK 20260920000000_drop_claims.sql (2.66ms)9942026/10/01 07:34:35 OK 20260905000000_add_claims.sql (3.12ms)9952026/10/01 07:34:35 OK 20260923120000_add_pushes.sql (2.31ms)9962026/10/01 07:34:35 goose: successfully migrated database to version: 202609231200009972026/10/01 07:34:35 OK 1_commit_pending_closure.sql (2.01ms)9982026/10/01 07:34:35 OK 2_object_stats_trigger.sql (523.33µs)9992026/10/01 07:34:35 OK 3_commit_push.sql (459.25µs)10002026/10/01 07:34:35 goose: up to current file version: 310012026/10/01 07:34:35 OK 20260920000000_drop_claims.sql (13.69ms)10022026/10/01 07:34:35 OK 20260923120000_add_pushes.sql (7.78ms)10032026/10/01 07:34:35 goose: successfully migrated database to version: 2026092312000010042026/10/01 07:34:35 OK 1_commit_pending_closure.sql (1.98ms)10052026/10/01 07:34:35 OK 2_object_stats_trigger.sql (635.21µs)10062026/10/01 07:34:35 OK 3_commit_push.sql (441.46µs)10072026/10/01 07:34:35 goose: up to current file version: 31008=== NAME TestClientMultipleUploads1009 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-37277-823233434/TestClientMultipleUploads10913960/001/store/p3bfwmcj76yy754vcs547k15q9nxzlxg-test-file-2.txt10102026/10/01 07:34:35 INFO Received push request method=POST path=/api/pushes10112026-10-01 07:34:35.794 UTC [38557] ERROR: relation "goose_db_version" does not exist at character 3610122026-10-01 07:34:35.794 UTC [38557] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10132026/10/01 07:34:35 INFO Aborted multipart uploads count=010142026/10/01 07:34:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10152026/10/01 07:34:35 INFO Uploading 4nz74b21l88p90w3kj623imdgspzwp22-test-file-0.txt (160B)10162026/10/01 07:34:35 INFO Uploading p3bfwmcj76yy754vcs547k15q9nxzlxg-test-file-2.txt (160B)10172026/10/01 07:34:35 INFO Uploading cd1k279lg4n2djglydif64czamwaxbh5-test-file-1.txt (160B)10182026/10/01 07:34:35 WARN Force mode enabled - objects will be deleted immediately without grace period10192026/10/01 07:34:35 WARN Failed to register uploaded object key=p3bfwmcj76yy754vcs547k15q9nxzlxg.ls error="server returned 404: 404 page not found\n"10202026/10/01 07:34:35 WARN Failed to register uploaded object key=4nz74b21l88p90w3kj623imdgspzwp22.ls error="server returned 404: 404 page not found\n"10212026/10/01 07:34:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10222026/10/01 07:34:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10232026/10/01 07:34:35 WARN Failed to register uploaded object key=cd1k279lg4n2djglydif64czamwaxbh5.ls error="server returned 404: 404 page not found\n"10242026/10/01 07:34:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10252026/10/01 07:34:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10262026/10/01 07:34:35 INFO Signed narinfos id=1 count=310272026/10/01 07:34:35 INFO Uploading 3 narinfos10282026/10/01 07:34:35 WARN Failed to register uploaded object key=4nz74b21l88p90w3kj623imdgspzwp22.narinfo error="server returned 404: 404 page not found\n"10292026/10/01 07:34:35 INFO Received complete push request method=POST path=/api/pushes/1/complete10302026/10/01 07:34:35 WARN Failed to register uploaded object key=cd1k279lg4n2djglydif64czamwaxbh5.narinfo error="server returned 404: 404 page not found\n"10312026/10/01 07:34:35 WARN Failed to register uploaded object key=p3bfwmcj76yy754vcs547k15q9nxzlxg.narinfo error="server returned 404: 404 page not found\n"10322026/10/01 07:34:35 INFO Upload complete. (204ms)1033 client_integration_test.go:369: Uploaded 3 paths in 279.126542ms1034--- PASS: TestClientMultipleUploads (2.77s)1035=== CONT TestClientErrorHandling1036=== RUN TestClientErrorHandling/InvalidStorePath1037=== PAUSE TestClientErrorHandling/InvalidStorePath1038=== RUN TestClientErrorHandling/InvalidAuthToken1039=== PAUSE TestClientErrorHandling/InvalidAuthToken1040=== RUN TestClientErrorHandling/ServerNotAvailable1041=== PAUSE TestClientErrorHandling/ServerNotAvailable1042=== CONT TestClientCADerivations10432026/10/01 07:34:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=010442026/10/01 07:34:35 OK 20241026095416_initial_model.sql (79.07ms)10452026/10/01 07:34:35 INFO Vacuumed table table=pending_closures10462026/10/01 07:34:35 INFO Vacuumed table table=pending_objects10472026/10/01 07:34:35 INFO Vacuumed table table=multipart_uploads10482026/10/01 07:34:35 INFO Vacuumed table table=closures10492026/10/01 07:34:35 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)10502026/10/01 07:34:35 INFO Vacuumed table table=objects1051--- PASS: TestGCSweepDeliversEachKeyOnce (2.23s)1052=== CONT TestCacheStatsHandler10532026/10/01 07:34:35 OK 20251218171726_add_pins.sql (42.31ms)10542026-10-01 07:34:35.992 UTC [38571] ERROR: relation "goose_db_version" does not exist at character 3610552026-10-01 07:34:35.992 UTC [38571] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10562026/10/01 07:34:36 OK 20260628120000_add_object_size_and_stats.sql (16.03ms)10572026/10/01 07:34:36 OK 20260905000000_add_claims.sql (30.66ms)10582026/10/01 07:34:36 OK 20260920000000_drop_claims.sql (15.68ms)10592026/10/01 07:34:36 OK 20260923120000_add_pushes.sql (31.95ms)10602026/10/01 07:34:36 goose: successfully migrated database to version: 2026092312000010612026/10/01 07:34:36 INFO Received uploads request method=POST path=/api/pending_closures10622026/10/01 07:34:36 OK 1_commit_pending_closure.sql (2.47ms)10632026/10/01 07:34:36 OK 2_object_stats_trigger.sql (3.34ms)10642026-10-01 07:34:36.089 UTC [38584] ERROR: relation "goose_db_version" does not exist at character 3610652026-10-01 07:34:36.089 UTC [38584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10662026/10/01 07:34:36 OK 3_commit_push.sql (5.62ms)10672026/10/01 07:34:36 goose: up to current file version: 310682026/10/01 07:34:36 OK 20241026095416_initial_model.sql (121.8ms)10692026/10/01 07:34:36 OK 20251210153512_drop_unused_gin_index.sql (6.04ms)10702026/10/01 07:34:36 OK 20251218171726_add_pins.sql (6.68ms)10712026/10/01 07:34:36 OK 20241026095416_initial_model.sql (40.65ms)10722026/10/01 07:34:36 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)10732026/10/01 07:34:36 OK 20260628120000_add_object_size_and_stats.sql (16.77ms)10742026/10/01 07:34:36 OK 20251218171726_add_pins.sql (10.16ms)10752026/10/01 07:34:36 OK 20260905000000_add_claims.sql (17.3ms)10762026/10/01 07:34:36 OK 20260628120000_add_object_size_and_stats.sql (16.65ms)10772026/10/01 07:34:36 OK 20260920000000_drop_claims.sql (10.05ms)10782026/10/01 07:34:36 OK 20260923120000_add_pushes.sql (8.82ms)10792026/10/01 07:34:36 goose: successfully migrated database to version: 2026092312000010802026/10/01 07:34:36 OK 20260905000000_add_claims.sql (9.95ms)10812026/10/01 07:34:36 OK 1_commit_pending_closure.sql (2.42ms)10822026/10/01 07:34:36 OK 20260920000000_drop_claims.sql (2.64ms)10832026/10/01 07:34:36 OK 2_object_stats_trigger.sql (675.71µs)10842026/10/01 07:34:36 OK 3_commit_push.sql (592.17µs)10852026/10/01 07:34:36 goose: up to current file version: 310862026/10/01 07:34:36 OK 20260923120000_add_pushes.sql (7.11ms)10872026/10/01 07:34:36 goose: successfully migrated database to version: 2026092312000010882026/10/01 07:34:36 OK 1_commit_pending_closure.sql (2.16ms)10892026/10/01 07:34:36 OK 2_object_stats_trigger.sql (584.79µs)10902026/10/01 07:34:36 OK 3_commit_push.sql (453.17µs)10912026/10/01 07:34:36 goose: up to current file version: 31092--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.68s)1093=== CONT TestCacheConfigHandler1094=== RUN TestCacheConfigHandler/full_config,_no_issuer1095=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1096=== RUN TestCacheConfigHandler/no_cache_url_configured1097=== PAUSE TestCacheConfigHandler/no_cache_url_configured1098=== RUN TestCacheConfigHandler/no_signing_keys1099=== PAUSE TestCacheConfigHandler/no_signing_keys1100=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1101=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1102=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11032026/10/01 07:34:36 INFO Received uploads request method=POST path=/api/pending_closures11042026-10-01 07:34:36.337 UTC [38595] ERROR: relation "goose_db_version" does not exist at character 3611052026-10-01 07:34:36.337 UTC [38595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11062026/10/01 07:34:36 INFO Aborted multipart uploads count=011072026/10/01 07:34:36 WARN Force mode enabled - objects will be deleted immediately without grace period11082026/10/01 07:34:36 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=011092026/10/01 07:34:36 INFO Vacuumed table table=pending_closures11102026/10/01 07:34:36 INFO Vacuumed table table=pending_objects11112026/10/01 07:34:36 INFO Vacuumed table table=multipart_uploads11122026/10/01 07:34:36 INFO Vacuumed table table=closures11132026/10/01 07:34:36 INFO Vacuumed table table=objects1114--- PASS: TestGCSweepSkipsPendingObjects (2.15s)1115=== CONT TestService_verifyS3Integrity11162026/10/01 07:34:36 OK 20241026095416_initial_model.sql (65.66ms)11172026/10/01 07:34:36 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)11182026/10/01 07:34:36 OK 20251218171726_add_pins.sql (18.73ms)11192026/10/01 07:34:36 OK 20260628120000_add_object_size_and_stats.sql (24.75ms)11202026/10/01 07:34:36 INFO Received uploads request method=POST path=/api/pending_closures11212026/10/01 07:34:36 OK 20260905000000_add_claims.sql (19.84ms)11222026/10/01 07:34:36 OK 20260920000000_drop_claims.sql (20.71ms)11232026/10/01 07:34:36 OK 20260923120000_add_pushes.sql (14.55ms)11242026/10/01 07:34:36 goose: successfully migrated database to version: 2026092312000011252026/10/01 07:34:36 OK 1_commit_pending_closure.sql (2ms)11262026/10/01 07:34:36 OK 2_object_stats_trigger.sql (594.96µs)11272026/10/01 07:34:36 OK 3_commit_push.sql (410.79µs)11282026/10/01 07:34:36 goose: up to current file version: 311292026/10/01 07:34:36 INFO Aborted multipart uploads count=011302026/10/01 07:34:36 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011312026/10/01 07:34:36 INFO Vacuumed table table=pending_closures11322026/10/01 07:34:36 INFO Vacuumed table table=pending_objects11332026/10/01 07:34:36 INFO Vacuumed table table=multipart_uploads11342026/10/01 07:34:36 INFO Vacuumed table table=closures11352026/10/01 07:34:36 INFO Vacuumed table table=objects11362026/10/01 07:34:36 INFO Aborted multipart uploads count=011372026/10/01 07:34:36 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/10/01 07:34:36 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=011392026/10/01 07:34:36 INFO Vacuumed table table=pending_closures11402026/10/01 07:34:36 INFO Vacuumed table table=pending_objects11412026/10/01 07:34:36 INFO Vacuumed table table=multipart_uploads11422026/10/01 07:34:36 INFO Vacuumed table table=closures11432026/10/01 07:34:36 INFO Vacuumed table table=objects1144--- PASS: TestPushDedupSurvivesConcurrentGC (1.87s)1145=== CONT TestService_createPendingClosureHandler11462026-10-01 07:34:36.764 UTC [38655] ERROR: relation "goose_db_version" does not exist at character 3611472026-10-01 07:34:36.764 UTC [38655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026-10-01 07:34:36.833 UTC [38686] ERROR: relation "goose_db_version" does not exist at character 3611492026-10-01 07:34:36.833 UTC [38686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11502026/10/01 07:34:36 OK 20241026095416_initial_model.sql (63.99ms)11512026/10/01 07:34:36 INFO Aborted multipart uploads count=011522026/10/01 07:34:36 WARN Force mode enabled - objects will be deleted immediately without grace period11532026/10/01 07:34:36 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=011542026/10/01 07:34:36 INFO Vacuumed table table=pending_closures11552026/10/01 07:34:36 INFO Vacuumed table table=pending_objects11562026/10/01 07:34:36 INFO Vacuumed table table=multipart_uploads11572026/10/01 07:34:36 INFO Vacuumed table table=closures11582026/10/01 07:34:36 INFO Vacuumed table table=objects1159--- PASS: TestGCMetrics (1.86s)1160=== CONT TestService_cleanupPendingClosuresHandler11612026/10/01 07:34:36 OK 20251210153512_drop_unused_gin_index.sql (16.39ms)11622026/10/01 07:34:36 OK 20251218171726_add_pins.sql (22.07ms)11632026/10/01 07:34:36 OK 20260628120000_add_object_size_and_stats.sql (13.26ms)1164--- PASS: TestGCBugBareHashReferences (2.30s)1165=== CONT TestUploadHandlersRejectOversizedBody11662026/10/01 07:34:36 OK 20260905000000_add_claims.sql (15.9ms)11672026/10/01 07:34:36 OK 20260920000000_drop_claims.sql (9.8ms)11682026/10/01 07:34:36 OK 20241026095416_initial_model.sql (80ms)1169=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1170=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1171=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1172=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1173=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1174=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1175=== CONT TestUploadHandlersRejectInvalidKeys1176=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1177=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1178=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1179=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1180=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1181=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1182=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1183=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1184=== CONT TestIsValidUploadKey1185=== RUN TestIsValidUploadKey/narinfo1186=== PAUSE TestIsValidUploadKey/narinfo1187=== RUN TestIsValidUploadKey/nar_zst1188=== PAUSE TestIsValidUploadKey/nar_zst1189=== RUN TestIsValidUploadKey/nar_xz1190=== PAUSE TestIsValidUploadKey/nar_xz1191=== RUN TestIsValidUploadKey/nar_plain1192=== PAUSE TestIsValidUploadKey/nar_plain1193=== RUN TestIsValidUploadKey/listing1194=== PAUSE TestIsValidUploadKey/listing1195=== RUN TestIsValidUploadKey/build_log1196=== PAUSE TestIsValidUploadKey/build_log1197=== RUN TestIsValidUploadKey/build_log_home-manager_file1198=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1199=== RUN TestIsValidUploadKey/build_log_plus_in_name1200=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1201=== RUN TestIsValidUploadKey/build_log_question_mark1202=== PAUSE TestIsValidUploadKey/build_log_question_mark1203=== RUN TestIsValidUploadKey/build_log_equals1204=== PAUSE TestIsValidUploadKey/build_log_equals1205=== RUN TestIsValidUploadKey/realisation1206=== PAUSE TestIsValidUploadKey/realisation1207=== RUN TestIsValidUploadKey/realisation_plus_in_output1208=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1209=== RUN TestIsValidUploadKey/nix-cache-info1210=== PAUSE TestIsValidUploadKey/nix-cache-info1211=== RUN TestIsValidUploadKey/index.html1212=== PAUSE TestIsValidUploadKey/index.html1213=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1214=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1215=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1216=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1217=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1218=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1219=== RUN TestIsValidUploadKey/traversal1220=== PAUSE TestIsValidUploadKey/traversal1221=== RUN TestIsValidUploadKey/traversal_nar1222=== PAUSE TestIsValidUploadKey/traversal_nar1223=== RUN TestIsValidUploadKey/absolute1224=== PAUSE TestIsValidUploadKey/absolute1225=== RUN TestIsValidUploadKey/empty_key1226=== PAUSE TestIsValidUploadKey/empty_key1227=== RUN TestIsValidUploadKey/unknown_type1228=== PAUSE TestIsValidUploadKey/unknown_type1229=== CONT TestProxyWriteTimeout1230=== RUN TestProxyWriteTimeout/narinfo1231=== PAUSE TestProxyWriteTimeout/narinfo1232=== RUN TestProxyWriteTimeout/1_GiB_nar1233=== PAUSE TestProxyWriteTimeout/1_GiB_nar1234=== RUN TestProxyWriteTimeout/10_GiB_nar1235=== PAUSE TestProxyWriteTimeout/10_GiB_nar1236=== RUN TestProxyWriteTimeout/unknown_size1237=== PAUSE TestProxyWriteTimeout/unknown_size1238=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12392026/10/01 07:34:36 OK 20260923120000_add_pushes.sql (8.42ms)12402026/10/01 07:34:36 goose: successfully migrated database to version: 2026092312000012412026/10/01 07:34:36 OK 20251210153512_drop_unused_gin_index.sql (6.79ms)12422026/10/01 07:34:36 OK 1_commit_pending_closure.sql (2.74ms)12432026/10/01 07:34:36 OK 20251218171726_add_pins.sql (2.8ms)12442026/10/01 07:34:36 OK 2_object_stats_trigger.sql (615.67µs)12452026/10/01 07:34:36 OK 3_commit_push.sql (966.96µs)12462026/10/01 07:34:36 goose: up to current file version: 312472026/10/01 07:34:36 OK 20260628120000_add_object_size_and_stats.sql (20.96ms)12482026/10/01 07:34:36 OK 20260905000000_add_claims.sql (21.59ms)12492026/10/01 07:34:37 OK 20260920000000_drop_claims.sql (20.21ms)12502026/10/01 07:34:37 OK 20260923120000_add_pushes.sql (11.3ms)12512026/10/01 07:34:37 goose: successfully migrated database to version: 2026092312000012522026/10/01 07:34:37 OK 1_commit_pending_closure.sql (2.42ms)12532026/10/01 07:34:37 INFO lead: acquired remote=192.0.2.1:123412542026/10/01 07:34:37 INFO lead: released remote=192.0.2.1:12341255--- PASS: TestLeadEndsOnShutdown (1.94s)1256=== CONT TestSkippedUploadsHandler12572026/10/01 07:34:37 INFO Client skipped oversized paths paths=3 nar_bytes=500000000012582026/10/01 07:34:37 OK 2_object_stats_trigger.sql (39.88ms)1259--- PASS: TestSkippedUploadsHandler (0.00s)1260=== CONT TestParseSize1261--- PASS: TestParseSize (0.00s)1262=== CONT TestService_Rustfstest12632026/10/01 07:34:37 OK 3_commit_push.sql (1.73ms)12642026/10/01 07:34:37 goose: up to current file version: 312652026-10-01 07:34:37.144 UTC [38742] ERROR: relation "goose_db_version" does not exist at character 3612662026-10-01 07:34:37.144 UTC [38742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12672026/10/01 07:34:37 OK 20241026095416_initial_model.sql (58.71ms)12682026/10/01 07:34:37 OK 20251210153512_drop_unused_gin_index.sql (6.29ms)12692026/10/01 07:34:37 OK 20251218171726_add_pins.sql (21.19ms)1270--- PASS: TestService_ReadScope_PublicByDefault (1.96s)1271=== CONT TestPresignedUploadRegisteredBeforeCommit12722026/10/01 07:34:37 OK 20260628120000_add_object_size_and_stats.sql (29.08ms)12732026/10/01 07:34:37 OK 20260905000000_add_claims.sql (28.82ms)12742026/10/01 07:34:37 OK 20260920000000_drop_claims.sql (14.35ms)12752026/10/01 07:34:37 OK 20260923120000_add_pushes.sql (1.99ms)12762026/10/01 07:34:37 goose: successfully migrated database to version: 2026092312000012772026/10/01 07:34:37 OK 1_commit_pending_closure.sql (2.18ms)12782026/10/01 07:34:37 OK 2_object_stats_trigger.sql (537.08µs)12792026/10/01 07:34:37 OK 3_commit_push.sql (442.75µs)12802026/10/01 07:34:37 goose: up to current file version: 312812026-10-01 07:34:37.344 UTC [38791] ERROR: relation "goose_db_version" does not exist at character 3612822026-10-01 07:34:37.344 UTC [38791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12832026/10/01 07:34:37 OK 20241026095416_initial_model.sql (118.14ms)12842026/10/01 07:34:37 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)12852026/10/01 07:34:37 OK 20251218171726_add_pins.sql (17.09ms)12862026/10/01 07:34:37 OK 20260628120000_add_object_size_and_stats.sql (28.27ms)12872026/10/01 07:34:37 OK 20260905000000_add_claims.sql (17.09ms)12882026/10/01 07:34:37 OK 20260920000000_drop_claims.sql (19.27ms)12892026/10/01 07:34:37 OK 20260923120000_add_pushes.sql (9.3ms)12902026/10/01 07:34:37 goose: successfully migrated database to version: 2026092312000012912026/10/01 07:34:37 OK 1_commit_pending_closure.sql (2.14ms)12922026/10/01 07:34:37 OK 2_object_stats_trigger.sql (591.08µs)12932026/10/01 07:34:37 OK 3_commit_push.sql (453.04µs)12942026/10/01 07:34:37 goose: up to current file version: 312952026-10-01 07:34:37.598 UTC [38806] ERROR: relation "goose_db_version" does not exist at character 3612962026-10-01 07:34:37.598 UTC [38806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1297=== NAME TestClientIntegration1298 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-37277-823233434/TestClientIntegration2410316050/002/store/ylqrq23rn13bq5m22ly4gmn5ic6avfrm-test-file.txt12992026/10/01 07:34:37 OK 20241026095416_initial_model.sql (121.79ms)13002026/10/01 07:34:37 OK 20251210153512_drop_unused_gin_index.sql (13.69ms)13012026/10/01 07:34:37 INFO Received push request method=POST path=/api/pushes13022026/10/01 07:34:37 OK 20251218171726_add_pins.sql (24.67ms)13032026/10/01 07:34:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13042026/10/01 07:34:37 INFO Uploading ylqrq23rn13bq5m22ly4gmn5ic6avfrm-test-file.txt (152B)13052026/10/01 07:34:37 OK 20260628120000_add_object_size_and_stats.sql (27.04ms)13062026/10/01 07:34:37 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13072026/10/01 07:34:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13082026/10/01 07:34:37 WARN Failed to register uploaded object key=ylqrq23rn13bq5m22ly4gmn5ic6avfrm.ls error="server returned 404: 404 page not found\n"13092026/10/01 07:34:37 INFO Signed narinfos id=1 count=113102026/10/01 07:34:37 INFO Uploading 1 narinfos13112026/10/01 07:34:37 INFO Received complete push request method=POST path=/api/pushes/1/complete13122026/10/01 07:34:37 WARN Failed to register uploaded object key=ylqrq23rn13bq5m22ly4gmn5ic6avfrm.narinfo error="server returned 404: 404 page not found\n"13132026-10-01 07:34:37.858 UTC [38821] ERROR: relation "goose_db_version" does not exist at character 3613142026-10-01 07:34:37.858 UTC [38821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13152026/10/01 07:34:37 OK 20260905000000_add_claims.sql (43.58ms)13162026/10/01 07:34:37 INFO Upload complete. (178ms)13172026/10/01 07:34:37 OK 20260920000000_drop_claims.sql (38.43ms)13182026-10-01 07:34:37.911 UTC [38827] ERROR: relation "goose_db_version" does not exist at character 3613192026-10-01 07:34:37.911 UTC [38827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13202026-10-01 07:34:37.911 UTC [38826] ERROR: relation "goose_db_version" does not exist at character 3613212026-10-01 07:34:37.911 UTC [38826] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13222026/10/01 07:34:37 OK 20260923120000_add_pushes.sql (28.48ms)13232026/10/01 07:34:37 goose: successfully migrated database to version: 2026092312000013242026/10/01 07:34:37 OK 1_commit_pending_closure.sql (7.9ms)13252026/10/01 07:34:37 OK 2_object_stats_trigger.sql (2.63ms)13262026/10/01 07:34:37 OK 3_commit_push.sql (2.24ms)13272026/10/01 07:34:37 goose: up to current file version: 313282026/10/01 07:34:37 INFO All 1 paths already cached1329 client_integration_test.go:312: Retrieved narinfo from S3:1330 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientIntegration2410316050/002/store/ylqrq23rn13bq5m22ly4gmn5ic6avfrm-test-file.txt1331 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1332 Compression: zstd1333 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11334 NarSize: 1521335 References: 1336 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11337 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1338 client_integration_test.go:313: Decompressed .ls content (64 bytes):1339 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1340 client_integration_test.go:316: Testing garbage collection...13412026/10/01 07:34:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures13422026/10/01 07:34:38 INFO Garbage collection started13432026/10/01 07:34:38 INFO Aborted multipart uploads count=013442026/10/01 07:34:38 WARN Force mode enabled - objects will be deleted immediately without grace period1345--- PASS: TestCacheStatsHandler (2.08s)1346=== CONT TestCompletedNarNotReofferedAcrossClosures13472026/10/01 07:34:38 OK 20241026095416_initial_model.sql (115.01ms)13482026/10/01 07:34:38 OK 20241026095416_initial_model.sql (136.45ms)13492026/10/01 07:34:38 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)13502026/10/01 07:34:38 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)13512026/10/01 07:34:38 OK 20241026095416_initial_model.sql (101.33ms)13522026/10/01 07:34:38 OK 20251218171726_add_pins.sql (3.29ms)13532026/10/01 07:34:38 OK 20251218171726_add_pins.sql (3.92ms)13542026/10/01 07:34:38 OK 20251210153512_drop_unused_gin_index.sql (4.96ms)13552026/10/01 07:34:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013562026/10/01 07:34:38 OK 20260628120000_add_object_size_and_stats.sql (23.55ms)13572026/10/01 07:34:38 OK 20260628120000_add_object_size_and_stats.sql (34.06ms)13582026/10/01 07:34:38 OK 20251218171726_add_pins.sql (38.88ms)13592026/10/01 07:34:38 INFO Vacuumed table table=pending_closures13602026/10/01 07:34:38 OK 20260628120000_add_object_size_and_stats.sql (24.56ms)13612026/10/01 07:34:38 INFO Vacuumed table table=pending_objects13622026/10/01 07:34:38 INFO Vacuumed table table=multipart_uploads13632026/10/01 07:34:38 OK 20260905000000_add_claims.sql (40ms)13642026/10/01 07:34:38 OK 20260905000000_add_claims.sql (51.71ms)13652026/10/01 07:34:38 INFO Vacuumed table table=closures13662026/10/01 07:34:38 OK 20260920000000_drop_claims.sql (18.56ms)13672026/10/01 07:34:38 OK 20260920000000_drop_claims.sql (19.93ms)13682026/10/01 07:34:38 OK 20260905000000_add_claims.sql (29.94ms)13692026/10/01 07:34:38 INFO Vacuumed table table=objects13702026/10/01 07:34:38 OK 20260923120000_add_pushes.sql (8.39ms)13712026/10/01 07:34:38 goose: successfully migrated database to version: 2026092312000013722026/10/01 07:34:38 OK 20260923120000_add_pushes.sql (8.6ms)13732026/10/01 07:34:38 goose: successfully migrated database to version: 2026092312000013742026/10/01 07:34:38 OK 1_commit_pending_closure.sql (1.87ms)13752026/10/01 07:34:38 OK 2_object_stats_trigger.sql (390.58µs)13762026/10/01 07:34:38 OK 1_commit_pending_closure.sql (2.13ms)13772026/10/01 07:34:38 OK 3_commit_push.sql (361.96µs)13782026/10/01 07:34:38 goose: up to current file version: 313792026/10/01 07:34:38 OK 2_object_stats_trigger.sql (495.5µs)13802026/10/01 07:34:38 OK 3_commit_push.sql (427.75µs)13812026/10/01 07:34:38 goose: up to current file version: 31382=== NAME TestClientCADerivations1383 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-37277-823233434/TestClientCADerivations2202261505/001/store/f30wksdrl6rwnbc4zjj3584qn8gqg49a-ca-test13842026/10/01 07:34:38 OK 20260920000000_drop_claims.sql (14.16ms)13852026/10/01 07:34:38 OK 20260923120000_add_pushes.sql (16.9ms)13862026/10/01 07:34:38 goose: successfully migrated database to version: 2026092312000013872026/10/01 07:34:38 OK 1_commit_pending_closure.sql (2.15ms)13882026/10/01 07:34:38 OK 2_object_stats_trigger.sql (538.96µs)13892026/10/01 07:34:38 OK 3_commit_push.sql (382.29µs)13902026/10/01 07:34:38 goose: up to current file version: 313912026-10-01 07:34:38.236 UTC [38849] ERROR: relation "goose_db_version" does not exist at character 3613922026-10-01 07:34:38.236 UTC [38849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1393 client_ca_test.go:139: Found 1 dependencies (including self)13942026/10/01 07:34:38 INFO Received push request method=POST path=/api/pushes1395--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.10s)1396=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13972026/10/01 07:34:38 OK 20241026095416_initial_model.sql (133.21ms)13982026/10/01 07:34:38 OK 20251210153512_drop_unused_gin_index.sql (6.66ms)13992026/10/01 07:34:38 INFO Received push request method=POST path=/api/pushes14002026/10/01 07:34:38 OK 20251218171726_add_pins.sql (15.74ms)14012026/10/01 07:34:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14022026/10/01 07:34:38 INFO Uploading f30wksdrl6rwnbc4zjj3584qn8gqg49a-ca-test (144B)14032026/10/01 07:34:38 OK 20260628120000_add_object_size_and_stats.sql (15.69ms)14042026/10/01 07:34:38 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14052026/10/01 07:34:38 WARN Failed to register uploaded object key=f30wksdrl6rwnbc4zjj3584qn8gqg49a.ls error="server returned 404: 404 page not found\n"14062026/10/01 07:34:38 WARN Failed to register uploaded object key=log/6f01d8hlrwkvcxmass2l42977yz4q58f-ca-test.drv error="server returned 404: 404 page not found\n"14072026/10/01 07:34:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14082026/10/01 07:34:38 INFO Signed narinfos id=1 count=114092026/10/01 07:34:38 INFO Uploading 1 narinfos14102026/10/01 07:34:38 OK 20260905000000_add_claims.sql (34.14ms)14112026/10/01 07:34:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14122026/10/01 07:34:38 WARN Failed to register uploaded object key=f30wksdrl6rwnbc4zjj3584qn8gqg49a.narinfo error="server returned 404: 404 page not found\n"14132026/10/01 07:34:38 INFO Upload complete. (208ms)1414=== NAME TestClientCADerivations1415 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientCADerivations2202261505/001/store/f30wksdrl6rwnbc4zjj3584qn8gqg49a-ca-test1416 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1417 Compression: zstd1418 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1419 NarSize: 1441420 References: 1421 Deriver: /nix/var/nix/builds/nix-37277-823233434/TestClientCADerivations2202261505/001/store/6f01d8hlrwkvcxmass2l42977yz4q58f-ca-test.drv1422 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1423 client_ca_test.go:185: Checking for realisation files in S3...1424 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1425 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14262026/10/01 07:34:38 OK 20260920000000_drop_claims.sql (34.14ms)14272026/10/01 07:34:38 INFO Received uploads request method=POST path=/api/pending_closures14282026/10/01 07:34:38 OK 20260923120000_add_pushes.sql (10.35ms)14292026/10/01 07:34:38 goose: successfully migrated database to version: 2026092312000014302026/10/01 07:34:38 OK 1_commit_pending_closure.sql (1.25ms)14312026/10/01 07:34:38 OK 2_object_stats_trigger.sql (240.58µs)14322026/10/01 07:34:38 OK 3_commit_push.sql (286.75µs)14332026/10/01 07:34:38 goose: up to current file version: 31434 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket23?endpoint=http://localhost:55282®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-37277-823233434/TestClientCADerivations2202261505/001/store'1435 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11436--- PASS: TestClientCADerivations (2.79s)1437=== CONT TestRedundantMultipartUpload14382026/10/01 07:34:38 INFO Received uploads request method=POST path=/api/pending_closures14392026/10/01 07:34:38 INFO Received uploads request method=POST path=/api/pending_closures14402026/10/01 07:34:38 INFO Received uploads request method=POST path=/api/pending_closures14412026-10-01 07:34:38.930 UTC [38873] ERROR: relation "goose_db_version" does not exist at character 3614422026-10-01 07:34:38.930 UTC [38873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14432026/10/01 07:34:39 INFO Received cleanup request method=DELETE path=/api/pending_closures14442026/10/01 07:34:39 INFO Aborted multipart uploads count=014452026/10/01 07:34:39 INFO Received uploads request method=POST path=/api/pending_closures14462026/10/01 07:34:39 INFO Received cleanup request method=DELETE path=/api/pending_closures14472026/10/01 07:34:39 INFO Aborted multipart uploads count=114482026/10/01 07:34:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14492026-10-01 07:34:39.184 UTC [38821] ERROR: Closure does not exist: id=114502026-10-01 07:34:39.184 UTC [38821] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE14512026-10-01 07:34:39.184 UTC [38821] STATEMENT: -- name: CommitPendingClosure :exec1452 SELECT commit_pending_closure($1::bigint)1453 1454--- PASS: TestService_cleanupPendingClosuresHandler (2.31s)1455=== CONT TestPush_SignsNarinfosOfItsPendingObjects14562026/10/01 07:34:39 OK 20241026095416_initial_model.sql (227.86ms)14572026/10/01 07:34:39 OK 20251210153512_drop_unused_gin_index.sql (17.3ms)14582026/10/01 07:34:39 OK 20251218171726_add_pins.sql (50.46ms)14592026/10/01 07:34:39 OK 20260628120000_add_object_size_and_stats.sql (36.55ms)14602026/10/01 07:34:39 OK 20260905000000_add_claims.sql (70.36ms)14612026/10/01 07:34:39 OK 20260920000000_drop_claims.sql (48.01ms)14622026/10/01 07:34:39 INFO Received uploads request method=POST path=/api/pending_closures14632026/10/01 07:34:39 OK 20260923120000_add_pushes.sql (17.9ms)14642026/10/01 07:34:39 goose: successfully migrated database to version: 2026092312000014652026/10/01 07:34:39 OK 1_commit_pending_closure.sql (1.23ms)14662026/10/01 07:34:39 OK 2_object_stats_trigger.sql (294.33µs)14672026/10/01 07:34:39 OK 3_commit_push.sql (189.46µs)14682026/10/01 07:34:39 goose: up to current file version: 314692026/10/01 07:34:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1470--- PASS: TestService_Rustfstest (2.71s)1471=== CONT TestPush_RejectsBadRequests14722026/10/01 07:34:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14732026/10/01 07:34:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01474=== NAME TestClientIntegration1475 client_integration_test.go:323: Objects in database after GC:1476 client_integration_test.go:323: Successfully deleted all objects with GC --force14772026/10/01 07:34:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWI0ZmE4OTYtNjYzZC00OWIyLWIyNjEtZDM4YTU2YTU2N2VlLmZiYjk2NDFiLTg0YjgtNGM5NC05MjYyLWI4NzU1MWM0MGIyOXgxNzkwODQwMDc4NTgwNTAxMDAw parts=1014782026/10/01 07:34:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14792026/10/01 07:34:40 INFO Completed upload id=114802026/10/01 07:34:40 INFO Received uploads request method=POST path=/api/pending_closures14812026/10/01 07:34:40 INFO Received uploads request method=POST path=/api/pending_closures14822026/10/01 07:34:40 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14832026/10/01 07:34:40 WARN Found objects in DB but missing from S3, will re-upload count=11484--- PASS: TestService_verifyS3Integrity (3.63s)1485=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14862026/10/01 07:34:40 INFO Received uploads request method=POST path=/api/pending_closures1487--- PASS: TestClientIntegration (4.58s)1488=== CONT TestPush_CompleteCommitsEveryRoot14892026/10/01 07:34:40 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14902026/10/01 07:34:40 INFO Received uploads request method=POST path=/api/pending_closures1491--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.92s)1492=== CONT TestGracefulShutdownDrainsInflight14932026/10/01 07:34:40 INFO Starting HTTP server address=127.0.0.1:5545414942026/10/01 07:34:40 INFO Shutdown signal received, draining in-flight requests timeout=10s1495--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1496=== CONT TestCacheConfigHandlerMaxNarSize1497--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1498=== CONT TestGenerateLandingPage1499--- PASS: TestGenerateLandingPage (0.00s)1500=== CONT TestService_readinessHandler15012026/10/01 07:34:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15022026/10/01 07:34:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWI0ZmE4OTYtNjYzZC00OWIyLWIyNjEtZDM4YTU2YTU2N2VlLjQxYjI1MDZjLTQyNTUtNDIxMy04NjEyLWI2ZWYwNDljYTY4M3gxNzkwODQwMDc4ODMwMzI0MDAw parts=1015032026/10/01 07:34:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15042026/10/01 07:34:40 INFO Completed upload id=115052026/10/01 07:34:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015062026/10/01 07:34:40 INFO Received uploads request method=POST path=/api/pending_closures15072026/10/01 07:34:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures15082026/10/01 07:34:40 INFO Aborted multipart uploads count=015092026/10/01 07:34:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015102026/10/01 07:34:40 INFO Vacuumed table table=pending_closures15112026/10/01 07:34:40 INFO Vacuumed table table=pending_objects15122026/10/01 07:34:40 INFO Received uploads request method=POST path=/api/pending_closures15132026/10/01 07:34:40 INFO Vacuumed table table=multipart_uploads15142026/10/01 07:34:40 INFO Vacuumed table table=closures15152026/10/01 07:34:40 INFO Vacuumed table table=objects15162026-10-01 07:34:40.508 UTC [38905] ERROR: relation "goose_db_version" does not exist at character 3615172026-10-01 07:34:40.508 UTC [38905] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15182026/10/01 07:34:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001519--- PASS: TestService_createPendingClosureHandler (3.85s)1520=== CONT TestService_healthCheckHandler15212026-10-01 07:34:40.652 UTC [38910] ERROR: relation "goose_db_version" does not exist at character 3615222026-10-01 07:34:40.652 UTC [38910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15232026/10/01 07:34:40 OK 20241026095416_initial_model.sql (115.61ms)15242026/10/01 07:34:40 OK 20251210153512_drop_unused_gin_index.sql (13.11ms)15252026/10/01 07:34:40 OK 20251218171726_add_pins.sql (29.52ms)15262026/10/01 07:34:40 OK 20260628120000_add_object_size_and_stats.sql (13.55ms)15272026/10/01 07:34:40 OK 20260905000000_add_claims.sql (15.35ms)15282026/10/01 07:34:40 OK 20260920000000_drop_claims.sql (2.38ms)15292026/10/01 07:34:40 OK 20260923120000_add_pushes.sql (2ms)15302026/10/01 07:34:40 goose: successfully migrated database to version: 2026092312000015312026/10/01 07:34:40 OK 1_commit_pending_closure.sql (3.1ms)15322026/10/01 07:34:40 OK 2_object_stats_trigger.sql (1.04ms)15332026/10/01 07:34:40 OK 3_commit_push.sql (1.39ms)15342026/10/01 07:34:40 goose: up to current file version: 315352026/10/01 07:34:40 OK 20241026095416_initial_model.sql (131.43ms)15362026/10/01 07:34:40 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)15372026/10/01 07:34:40 OK 20251218171726_add_pins.sql (32.27ms)15382026/10/01 07:34:40 OK 20260628120000_add_object_size_and_stats.sql (52.83ms)15392026/10/01 07:34:41 OK 20260905000000_add_claims.sql (119.72ms)15402026/10/01 07:34:41 OK 20260920000000_drop_claims.sql (42.8ms)15412026/10/01 07:34:41 INFO Received uploads request method=POST path=/api/pending_closures15422026/10/01 07:34:41 OK 20260923120000_add_pushes.sql (20.28ms)15432026/10/01 07:34:41 goose: successfully migrated database to version: 2026092312000015442026/10/01 07:34:41 OK 1_commit_pending_closure.sql (978.38µs)15452026/10/01 07:34:41 OK 2_object_stats_trigger.sql (239.38µs)15462026/10/01 07:34:41 OK 3_commit_push.sql (177µs)15472026/10/01 07:34:41 goose: up to current file version: 315482026/10/01 07:34:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15492026-10-01 07:34:41.436 UTC [38926] ERROR: relation "goose_db_version" does not exist at character 3615502026-10-01 07:34:41.436 UTC [38926] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15512026/10/01 07:34:41 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWI0ZmE4OTYtNjYzZC00OWIyLWIyNjEtZDM4YTU2YTU2N2VlLmU1NDFhNDViLTk1MjctNGU5OS1iY2NlLTMzMDRkY2RhM2FkZXgxNzkwODQwMDgxMTUzMjYwMDAw15522026/10/01 07:34:41 INFO Received uploads request method=POST path=/api/pending_closures15532026/10/01 07:34:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWI0ZmE4OTYtNjYzZC00OWIyLWIyNjEtZDM4YTU2YTU2N2VlLmU1NDFhNDViLTk1MjctNGU5OS1iY2NlLTMzMDRkY2RhM2FkZXgxNzkwODQwMDgxMTUzMjYwMDAw parts=11554--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.06s)1555=== CONT TestService_ReadAuthMiddleware15562026/10/01 07:34:41 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/01 07:34:41 OK 20241026095416_initial_model.sql (217.78ms)15582026/10/01 07:34:41 OK 20251210153512_drop_unused_gin_index.sql (22.01ms)15592026/10/01 07:34:41 OK 20251218171726_add_pins.sql (20.73ms)15602026/10/01 07:34:41 OK 20260628120000_add_object_size_and_stats.sql (24.96ms)15612026/10/01 07:34:41 OK 20260905000000_add_claims.sql (17.91ms)15622026/10/01 07:34:41 OK 20260920000000_drop_claims.sql (81.65ms)15632026/10/01 07:34:41 OK 20260923120000_add_pushes.sql (24.2ms)15642026/10/01 07:34:41 goose: successfully migrated database to version: 2026092312000015652026/10/01 07:34:41 OK 1_commit_pending_closure.sql (903.88µs)15662026/10/01 07:34:41 OK 2_object_stats_trigger.sql (202.29µs)15672026/10/01 07:34:41 OK 3_commit_push.sql (164.54µs)15682026/10/01 07:34:41 goose: up to current file version: 315692026-10-01 07:34:41.969 UTC [38992] ERROR: relation "goose_db_version" does not exist at character 3615702026-10-01 07:34:41.969 UTC [38992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15712026-10-01 07:34:42.108 UTC [39005] ERROR: relation "goose_db_version" does not exist at character 3615722026-10-01 07:34:42.108 UTC [39005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/10/01 07:34:42 OK 20241026095416_initial_model.sql (193.23ms)15742026/10/01 07:34:42 OK 20251210153512_drop_unused_gin_index.sql (15.4ms)15752026/10/01 07:34:42 INFO Received push request method=POST path=/api/pushes15762026/10/01 07:34:42 OK 20251218171726_add_pins.sql (41.11ms)15772026/10/01 07:34:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15782026/10/01 07:34:42 OK 20260628120000_add_object_size_and_stats.sql (82.21ms)15792026-10-01 07:34:42.398 UTC [39044] ERROR: relation "goose_db_version" does not exist at character 3615802026-10-01 07:34:42.398 UTC [39044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15812026/10/01 07:34:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15822026/10/01 07:34:42 INFO Signed narinfos id=1 count=11583--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.22s)1584=== CONT TestService_RequireScope_OIDC15852026/10/01 07:34:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWI0ZmE4OTYtNjYzZC00OWIyLWIyNjEtZDM4YTU2YTU2N2VlLjc5ZDJiNDUyLTRhNzAtNDFiNy1hYjRkLTk4ODBiZjdjZjNlM3gxNzkwODQwMDgwNDU0ODEyMDAw parts=1215862026/10/01 07:34:42 INFO Received uploads request method=POST path=/api/pending_closures1587--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.38s)1588=== CONT TestService_AuthMiddleware_OIDC15892026/10/01 07:34:42 OK 20260905000000_add_claims.sql (79ms)15902026/10/01 07:34:42 OK 20241026095416_initial_model.sql (311.16ms)15912026/10/01 07:34:42 OK 20251210153512_drop_unused_gin_index.sql (15.26ms)15922026/10/01 07:34:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55464/oidc15932026/10/01 07:34:42 OK 20260920000000_drop_claims.sql (45.12ms)15942026/10/01 07:34:42 OK 20251218171726_add_pins.sql (28.96ms)15952026/10/01 07:34:42 OK 20260923120000_add_pushes.sql (19.29ms)15962026/10/01 07:34:42 goose: successfully migrated database to version: 2026092312000015972026/10/01 07:34:42 OK 1_commit_pending_closure.sql (944.5µs)15982026/10/01 07:34:42 OK 2_object_stats_trigger.sql (217.79µs)15992026/10/01 07:34:42 OK 3_commit_push.sql (178.25µs)16002026/10/01 07:34:42 goose: up to current file version: 316012026/10/01 07:34:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55467/oidc16022026/10/01 07:34:42 OK 20260628120000_add_object_size_and_stats.sql (35.18ms)16032026-10-01 07:34:42.620 UTC [39078] ERROR: relation "goose_db_version" does not exist at character 3616042026-10-01 07:34:42.620 UTC [39078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16052026/10/01 07:34:42 OK 20260905000000_add_claims.sql (84.72ms)16062026/10/01 07:34:42 OK 20260920000000_drop_claims.sql (86.45ms)16072026/10/01 07:34:42 OK 20260923120000_add_pushes.sql (52.02ms)16082026/10/01 07:34:42 goose: successfully migrated database to version: 2026092312000016092026/10/01 07:34:42 OK 20241026095416_initial_model.sql (288.18ms)16102026/10/01 07:34:42 OK 1_commit_pending_closure.sql (1.71ms)16112026/10/01 07:34:42 OK 2_object_stats_trigger.sql (249.38µs)16122026/10/01 07:34:42 OK 3_commit_push.sql (166.17µs)16132026/10/01 07:34:42 goose: up to current file version: 316142026/10/01 07:34:42 OK 20251210153512_drop_unused_gin_index.sql (16.76ms)16152026/10/01 07:34:42 OK 20251218171726_add_pins.sql (26.92ms)16162026/10/01 07:34:42 OK 20260628120000_add_object_size_and_stats.sql (43.02ms)16172026/10/01 07:34:42 INFO Received push request method=POST path=/api/pushes16182026/10/01 07:34:42 OK 20260905000000_add_claims.sql (123.42ms)16192026/10/01 07:34:43 INFO Received complete push request method=POST path=/api/pushes/1/complete16202026-10-01 07:34:43.030 UTC [39120] ERROR: relation "goose_db_version" does not exist at character 3616212026-10-01 07:34:43.030 UTC [39120] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/10/01 07:34:43 OK 20260920000000_drop_claims.sql (75.27ms)1623--- PASS: TestPush_CompleteCommitsEveryRoot (2.92s)1624=== CONT TestLeadElectsOneAndHandsOver16252026/10/01 07:34:43 OK 20241026095416_initial_model.sql (291.17ms)16262026/10/01 07:34:43 OK 20251210153512_drop_unused_gin_index.sql (20.77ms)16272026/10/01 07:34:43 OK 20260923120000_add_pushes.sql (36.95ms)16282026/10/01 07:34:43 goose: successfully migrated database to version: 2026092312000016292026/10/01 07:34:43 OK 1_commit_pending_closure.sql (983.21µs)16302026/10/01 07:34:43 OK 2_object_stats_trigger.sql (252.42µs)16312026/10/01 07:34:43 OK 3_commit_push.sql (184.5µs)16322026/10/01 07:34:43 goose: up to current file version: 316332026/10/01 07:34:43 OK 20251218171726_add_pins.sql (45.02ms)16342026/10/01 07:34:43 OK 20260628120000_add_object_size_and_stats.sql (39.25ms)16352026/10/01 07:34:43 OK 20260905000000_add_claims.sql (72.33ms)1636=== RUN TestPush_RejectsBadRequests/no_roots1637=== PAUSE TestPush_RejectsBadRequests/no_roots1638=== RUN TestPush_RejectsBadRequests/no_objects1639=== PAUSE TestPush_RejectsBadRequests/no_objects1640=== RUN TestPush_RejectsBadRequests/bad_root1641=== PAUSE TestPush_RejectsBadRequests/bad_root1642=== RUN TestPush_RejectsBadRequests/root_not_in_objects1643=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1644=== CONT TestGCTaskStore_PhaseUpdates1645--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1646=== CONT TestGCTaskStore_Fail1647--- PASS: TestGCTaskStore_Fail (0.00s)1648=== CONT TestGCTaskStore_CompletedAllowsNewTask1649--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1650=== CONT TestReadProxy40416512026/10/01 07:34:43 OK 20260920000000_drop_claims.sql (58.35ms)16522026/10/01 07:34:43 OK 20260923120000_add_pushes.sql (34.47ms)16532026/10/01 07:34:43 goose: successfully migrated database to version: 2026092312000016542026/10/01 07:34:43 OK 1_commit_pending_closure.sql (1.72ms)16552026/10/01 07:34:43 OK 2_object_stats_trigger.sql (259.67µs)16562026/10/01 07:34:43 OK 3_commit_push.sql (184.63µs)16572026/10/01 07:34:43 goose: up to current file version: 316582026/10/01 07:34:43 OK 20241026095416_initial_model.sql (233.01ms)16592026/10/01 07:34:43 OK 20251210153512_drop_unused_gin_index.sql (8.84ms)16602026/10/01 07:34:43 OK 20251218171726_add_pins.sql (9.76ms)16612026/10/01 07:34:43 OK 20260628120000_add_object_size_and_stats.sql (30.8ms)16622026/10/01 07:34:43 OK 20260905000000_add_claims.sql (49.62ms)16632026/10/01 07:34:43 OK 20260920000000_drop_claims.sql (36.56ms)16642026/10/01 07:34:43 OK 20260923120000_add_pushes.sql (18.61ms)16652026/10/01 07:34:43 goose: successfully migrated database to version: 2026092312000016662026/10/01 07:34:43 OK 1_commit_pending_closure.sql (960.79µs)16672026/10/01 07:34:43 OK 2_object_stats_trigger.sql (222.46µs)16682026/10/01 07:34:43 OK 3_commit_push.sql (175.63µs)16692026/10/01 07:34:43 goose: up to current file version: 316702026/10/01 07:34:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16712026/10/01 07:34:43 INFO Received push request method=POST path=/api/pushes16722026/10/01 07:34:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWI0ZmE4OTYtNjYzZC00OWIyLWIyNjEtZDM4YTU2YTU2N2VlLjhlMzM1Mjc2LWEwNjctNGUyYS1hNTZhLTJmNjRkMDkzYTE2ZHgxNzkwODQwMDgxNDk1Nzg2MDAw parts=121673--- PASS: TestRedundantMultipartUpload (4.93s)1674=== CONT TestReadRedirectUsesPublicS3URL16752026/10/01 07:34:43 INFO Received complete push request method=POST path=/api/pushes/1/complete16762026/10/01 07:34:43 INFO Received push request method=POST path=/api/pushes16772026/10/01 07:34:43 INFO Aborted multipart uploads count=016782026/10/01 07:34:43 WARN Force mode enabled - objects will be deleted immediately without grace period16792026/10/01 07:34:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=016802026/10/01 07:34:43 INFO Vacuumed table table=pending_closures16812026/10/01 07:34:43 INFO Vacuumed table table=pending_objects16822026-10-01 07:34:43.940 UTC [39238] ERROR: relation "goose_db_version" does not exist at character 3616832026-10-01 07:34:43.940 UTC [39238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16842026/10/01 07:34:43 WARN readiness check failed error="closed pool"1685--- PASS: TestService_readinessHandler (3.70s)1686=== CONT TestReadProxyRangeRequest16872026/10/01 07:34:43 INFO Vacuumed table table=multipart_uploads16882026/10/01 07:34:44 INFO Vacuumed table table=closures16892026/10/01 07:34:44 INFO Vacuumed table table=objects16902026/10/01 07:34:44 INFO Received complete push request method=POST path=/api/pushes/2/complete1691--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.97s)1692=== CONT TestReadRedirectKeepsNarinfoProxied16932026/10/01 07:34:44 OK 20241026095416_initial_model.sql (209.43ms)16942026/10/01 07:34:44 OK 20251210153512_drop_unused_gin_index.sql (18.46ms)16952026/10/01 07:34:44 WARN Rate limiter enabled after throttle name=s3-test rate=516962026/10/01 07:34:44 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1697=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1698 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101699 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001700--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.32s)1701=== CONT TestReadRedirectNar1702--- PASS: TestService_healthCheckHandler (3.74s)1703=== CONT TestReadProxyDisabled17042026/10/01 07:34:44 OK 20251218171726_add_pins.sql (37.98ms)17052026/10/01 07:34:44 OK 20260628120000_add_object_size_and_stats.sql (77.31ms)17062026/10/01 07:34:44 OK 20260905000000_add_claims.sql (41.44ms)17072026/10/01 07:34:44 OK 20260920000000_drop_claims.sql (16.07ms)17082026/10/01 07:34:44 OK 20260923120000_add_pushes.sql (3.57ms)17092026/10/01 07:34:44 goose: successfully migrated database to version: 2026092312000017102026/10/01 07:34:44 OK 1_commit_pending_closure.sql (1ms)17112026/10/01 07:34:44 OK 2_object_stats_trigger.sql (268.58µs)17122026/10/01 07:34:44 OK 3_commit_push.sql (198.13µs)17132026/10/01 07:34:44 goose: up to current file version: 317142026-10-01 07:34:44.576 UTC [39290] ERROR: relation "goose_db_version" does not exist at character 3617152026-10-01 07:34:44.576 UTC [39290] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17162026-10-01 07:34:44.589 UTC [39291] ERROR: relation "goose_db_version" does not exist at character 3617172026-10-01 07:34:44.589 UTC [39291] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1718--- PASS: TestService_ReadAuthMiddleware (3.26s)1719=== CONT TestReadProxyRootRedirectsToIndexHTML17202026/10/01 07:34:44 OK 20241026095416_initial_model.sql (97.9ms)17212026/10/01 07:34:44 OK 20241026095416_initial_model.sql (114.98ms)17222026/10/01 07:34:44 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)17232026/10/01 07:34:44 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)17242026/10/01 07:34:44 OK 20251218171726_add_pins.sql (7.04ms)17252026/10/01 07:34:44 OK 20251218171726_add_pins.sql (7.51ms)17262026-10-01 07:34:44.790 UTC [39309] ERROR: relation "goose_db_version" does not exist at character 3617272026-10-01 07:34:44.790 UTC [39309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17282026/10/01 07:34:44 OK 20260628120000_add_object_size_and_stats.sql (11.29ms)17292026/10/01 07:34:44 OK 20260628120000_add_object_size_and_stats.sql (11.84ms)17302026/10/01 07:34:44 OK 20260905000000_add_claims.sql (13.34ms)17312026/10/01 07:34:44 OK 20260905000000_add_claims.sql (13.32ms)17322026/10/01 07:34:44 OK 20260920000000_drop_claims.sql (41.19ms)17332026/10/01 07:34:44 OK 20260920000000_drop_claims.sql (42.03ms)17342026/10/01 07:34:44 OK 20260923120000_add_pushes.sql (16.67ms)17352026/10/01 07:34:44 goose: successfully migrated database to version: 2026092312000017362026/10/01 07:34:44 OK 20260923120000_add_pushes.sql (26.3ms)17372026/10/01 07:34:44 goose: successfully migrated database to version: 2026092312000017382026/10/01 07:34:44 OK 1_commit_pending_closure.sql (13.81ms)17392026/10/01 07:34:44 OK 1_commit_pending_closure.sql (3.47ms)17402026/10/01 07:34:44 OK 2_object_stats_trigger.sql (326.5µs)17412026/10/01 07:34:44 OK 2_object_stats_trigger.sql (249.67µs)17422026/10/01 07:34:44 OK 3_commit_push.sql (265.54µs)17432026/10/01 07:34:44 goose: up to current file version: 317442026/10/01 07:34:44 OK 3_commit_push.sql (265.67µs)17452026/10/01 07:34:44 goose: up to current file version: 317462026/10/01 07:34:44 OK 20241026095416_initial_model.sql (131.22ms)17472026/10/01 07:34:44 OK 20251210153512_drop_unused_gin_index.sql (6ms)17482026/10/01 07:34:44 OK 20251218171726_add_pins.sql (7.86ms)17492026-10-01 07:34:44.975 UTC [39313] ERROR: relation "goose_db_version" does not exist at character 3617502026-10-01 07:34:44.975 UTC [39313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17512026/10/01 07:34:44 OK 20260628120000_add_object_size_and_stats.sql (28.73ms)17522026/10/01 07:34:45 OK 20260905000000_add_claims.sql (25.3ms)17532026/10/01 07:34:45 OK 20260920000000_drop_claims.sql (30.18ms)17542026/10/01 07:34:45 OK 20260923120000_add_pushes.sql (10.34ms)17552026/10/01 07:34:45 goose: successfully migrated database to version: 2026092312000017562026/10/01 07:34:45 OK 1_commit_pending_closure.sql (1.02ms)17572026/10/01 07:34:45 OK 2_object_stats_trigger.sql (775.38µs)17582026/10/01 07:34:45 OK 3_commit_push.sql (172µs)17592026/10/01 07:34:45 goose: up to current file version: 317602026-10-01 07:34:45.121 UTC [39315] ERROR: relation "goose_db_version" does not exist at character 3617612026-10-01 07:34:45.121 UTC [39315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1762=== RUN TestService_RequireScope_OIDC/builder_may_write1763=== PAUSE TestService_RequireScope_OIDC/builder_may_write1764=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1765=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1766=== RUN TestService_RequireScope_OIDC/ops_may_admin1767=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1768=== RUN TestService_RequireScope_OIDC/ops_may_not_write1769=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1770=== RUN TestService_RequireScope_OIDC/reader_may_not_write1771=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1772=== RUN TestService_RequireScope_OIDC/static_token_may_admin1773=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1774=== RUN TestService_RequireScope_OIDC/static_token_may_write1775=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1776=== RUN TestService_RequireScope_OIDC/reader_may_read1777=== PAUSE TestService_RequireScope_OIDC/reader_may_read1778=== RUN TestService_RequireScope_OIDC/writer_implies_read1779=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1780=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1781=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1782=== CONT TestReadProxyConditionalGet17832026/10/01 07:34:45 OK 20241026095416_initial_model.sql (128.33ms)17842026/10/01 07:34:45 OK 20251210153512_drop_unused_gin_index.sql (15.21ms)17852026/10/01 07:34:45 OK 20251218171726_add_pins.sql (20.12ms)17862026/10/01 07:34:45 OK 20260628120000_add_object_size_and_stats.sql (19.8ms)17872026/10/01 07:34:45 OK 20260905000000_add_claims.sql (27.77ms)17882026/10/01 07:34:45 OK 20260920000000_drop_claims.sql (17.92ms)17892026/10/01 07:34:45 OK 20260923120000_add_pushes.sql (6.89ms)17902026/10/01 07:34:45 goose: successfully migrated database to version: 2026092312000017912026/10/01 07:34:45 OK 1_commit_pending_closure.sql (1.58ms)17922026/10/01 07:34:45 OK 2_object_stats_trigger.sql (237.13µs)17932026/10/01 07:34:45 OK 3_commit_push.sql (189.42µs)17942026/10/01 07:34:45 goose: up to current file version: 317952026/10/01 07:34:45 OK 20241026095416_initial_model.sql (93.95ms)17962026/10/01 07:34:45 OK 20251210153512_drop_unused_gin_index.sql (7.9ms)17972026/10/01 07:34:45 OK 20251218171726_add_pins.sql (30.41ms)17982026/10/01 07:34:45 OK 20260628120000_add_object_size_and_stats.sql (30.47ms)1799=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1800=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1801=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1802=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1803=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1804=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1805=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1806=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1807=== CONT TestReadProxyHead18082026/10/01 07:34:45 OK 20260905000000_add_claims.sql (60.03ms)18092026/10/01 07:34:45 OK 20260920000000_drop_claims.sql (15.46ms)18102026/10/01 07:34:45 OK 20260923120000_add_pushes.sql (2.74ms)18112026/10/01 07:34:45 goose: successfully migrated database to version: 2026092312000018122026/10/01 07:34:45 OK 1_commit_pending_closure.sql (1.65ms)18132026/10/01 07:34:45 OK 2_object_stats_trigger.sql (247.71µs)18142026/10/01 07:34:45 OK 3_commit_push.sql (189.71µs)18152026/10/01 07:34:45 goose: up to current file version: 318162026-10-01 07:34:45.583 UTC [39338] ERROR: relation "goose_db_version" does not exist at character 3618172026-10-01 07:34:45.583 UTC [39338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18182026-10-01 07:34:45.601 UTC [39337] ERROR: relation "goose_db_version" does not exist at character 3618192026-10-01 07:34:45.601 UTC [39337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18202026/10/01 07:34:45 INFO lead: acquired remote=192.0.2.1:123418212026-10-01 07:34:45.764 UTC [39347] ERROR: relation "goose_db_version" does not exist at character 3618222026-10-01 07:34:45.764 UTC [39347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18232026/10/01 07:34:45 OK 20241026095416_initial_model.sql (116.67ms)18242026/10/01 07:34:45 OK 20241026095416_initial_model.sql (120.89ms)18252026/10/01 07:34:45 OK 20251210153512_drop_unused_gin_index.sql (7.97ms)18262026/10/01 07:34:45 OK 20251210153512_drop_unused_gin_index.sql (8.61ms)18272026/10/01 07:34:45 OK 20251218171726_add_pins.sql (6.61ms)18282026/10/01 07:34:45 OK 20251218171726_add_pins.sql (18.54ms)18292026/10/01 07:34:45 INFO lead: released remote=192.0.2.1:123418302026/10/01 07:34:45 OK 20260628120000_add_object_size_and_stats.sql (18.9ms)18312026/10/01 07:34:45 OK 20260628120000_add_object_size_and_stats.sql (21.63ms)18322026/10/01 07:34:45 OK 20260905000000_add_claims.sql (33.58ms)18332026/10/01 07:34:45 INFO lead: acquired remote=192.0.2.1:123418342026/10/01 07:34:45 INFO lead: released remote=192.0.2.1:12341835--- PASS: TestLeadElectsOneAndHandsOver (2.79s)1836=== CONT TestReadProxyInvalidPath18372026-10-01 07:34:45.859 UTC [39349] ERROR: relation "goose_db_version" does not exist at character 3618382026-10-01 07:34:45.859 UTC [39349] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18392026/10/01 07:34:45 OK 20260905000000_add_claims.sql (44.77ms)18402026/10/01 07:34:45 OK 20260920000000_drop_claims.sql (25.74ms)18412026/10/01 07:34:45 OK 20260923120000_add_pushes.sql (7.96ms)18422026/10/01 07:34:45 goose: successfully migrated database to version: 2026092312000018432026/10/01 07:34:45 OK 1_commit_pending_closure.sql (965.96µs)18442026/10/01 07:34:45 OK 2_object_stats_trigger.sql (237.71µs)18452026/10/01 07:34:45 OK 3_commit_push.sql (196.71µs)18462026/10/01 07:34:45 goose: up to current file version: 318472026/10/01 07:34:45 OK 20260920000000_drop_claims.sql (21.13ms)18482026/10/01 07:34:45 OK 20260923120000_add_pushes.sql (14.89ms)18492026/10/01 07:34:45 goose: successfully migrated database to version: 2026092312000018502026/10/01 07:34:45 OK 1_commit_pending_closure.sql (828µs)18512026/10/01 07:34:45 OK 2_object_stats_trigger.sql (213.67µs)18522026/10/01 07:34:45 OK 3_commit_push.sql (177.46µs)18532026/10/01 07:34:45 goose: up to current file version: 31854--- PASS: TestReadProxy404 (2.60s)1855=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18562026/10/01 07:34:45 OK 20241026095416_initial_model.sql (145.67ms)18572026/10/01 07:34:45 OK 20251210153512_drop_unused_gin_index.sql (9.45ms)18582026/10/01 07:34:45 OK 20251218171726_add_pins.sql (11.27ms)18592026/10/01 07:34:45 OK 20260628120000_add_object_size_and_stats.sql (19.79ms)18602026/10/01 07:34:46 OK 20241026095416_initial_model.sql (111.74ms)18612026/10/01 07:34:46 OK 20260905000000_add_claims.sql (27.62ms)18622026/10/01 07:34:46 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)18632026-10-01 07:34:46.030 UTC [39364] ERROR: relation "goose_db_version" does not exist at character 3618642026-10-01 07:34:46.030 UTC [39364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18652026/10/01 07:34:46 OK 20260920000000_drop_claims.sql (13.99ms)18662026/10/01 07:34:46 OK 20251218171726_add_pins.sql (19.49ms)18672026/10/01 07:34:46 OK 20260923120000_add_pushes.sql (10.75ms)18682026/10/01 07:34:46 goose: successfully migrated database to version: 2026092312000018692026/10/01 07:34:46 OK 1_commit_pending_closure.sql (4.9ms)18702026/10/01 07:34:46 OK 2_object_stats_trigger.sql (378.92µs)18712026/10/01 07:34:46 OK 3_commit_push.sql (311.25µs)18722026/10/01 07:34:46 goose: up to current file version: 318732026/10/01 07:34:46 OK 20260628120000_add_object_size_and_stats.sql (12.5ms)18742026/10/01 07:34:46 OK 20260905000000_add_claims.sql (33.09ms)18752026/10/01 07:34:46 OK 20260920000000_drop_claims.sql (13.75ms)18762026/10/01 07:34:46 OK 20260923120000_add_pushes.sql (11.09ms)18772026/10/01 07:34:46 goose: successfully migrated database to version: 2026092312000018782026/10/01 07:34:46 OK 1_commit_pending_closure.sql (1.77ms)18792026/10/01 07:34:46 OK 2_object_stats_trigger.sql (504.33µs)18802026/10/01 07:34:46 OK 3_commit_push.sql (285µs)18812026/10/01 07:34:46 goose: up to current file version: 318822026/10/01 07:34:46 OK 20241026095416_initial_model.sql (114.03ms)18832026/10/01 07:34:46 OK 20251210153512_drop_unused_gin_index.sql (9.78ms)1884--- PASS: TestReadRedirectUsesPublicS3URL (2.59s)1885=== CONT TestGCTaskStore_GetReturnsLatest1886--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1887=== CONT TestService_AuthMiddleware_MTLSProxyHeader18882026/10/01 07:34:46 OK 20251218171726_add_pins.sql (49.17ms)18892026/10/01 07:34:46 OK 20260628120000_add_object_size_and_stats.sql (25.65ms)18902026/10/01 07:34:46 OK 20260905000000_add_claims.sql (52.21ms)18912026/10/01 07:34:46 OK 20260920000000_drop_claims.sql (8.88ms)18922026/10/01 07:34:46 OK 20260923120000_add_pushes.sql (11.47ms)18932026/10/01 07:34:46 goose: successfully migrated database to version: 2026092312000018942026/10/01 07:34:46 OK 1_commit_pending_closure.sql (3.36ms)18952026/10/01 07:34:46 OK 2_object_stats_trigger.sql (4.76ms)18962026/10/01 07:34:46 OK 3_commit_push.sql (1.88ms)18972026/10/01 07:34:46 goose: up to current file version: 318982026-10-01 07:34:46.384 UTC [39402] ERROR: relation "goose_db_version" does not exist at character 3618992026-10-01 07:34:46.384 UTC [39402] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19002026/10/01 07:34:46 OK 20241026095416_initial_model.sql (70.5ms)19012026-10-01 07:34:46.516 UTC [39423] ERROR: relation "goose_db_version" does not exist at character 3619022026-10-01 07:34:46.516 UTC [39423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19032026/10/01 07:34:46 OK 20251210153512_drop_unused_gin_index.sql (53.46ms)19042026/10/01 07:34:46 OK 20251218171726_add_pins.sql (35.73ms)1905--- PASS: TestReadRedirectKeepsNarinfoProxied (2.58s)1906=== CONT TestProxyHeadersOnlyTrustedOnSocket19072026/10/01 07:34:46 OK 20260628120000_add_object_size_and_stats.sql (32.46ms)19082026/10/01 07:34:46 OK 20260905000000_add_claims.sql (21.47ms)19092026/10/01 07:34:46 OK 20241026095416_initial_model.sql (107.77ms)19102026/10/01 07:34:46 OK 20260920000000_drop_claims.sql (40.98ms)19112026/10/01 07:34:46 OK 20251210153512_drop_unused_gin_index.sql (18.43ms)19122026/10/01 07:34:46 OK 20260923120000_add_pushes.sql (26.84ms)19132026/10/01 07:34:46 goose: successfully migrated database to version: 2026092312000019142026/10/01 07:34:46 OK 1_commit_pending_closure.sql (3.27ms)19152026/10/01 07:34:46 OK 2_object_stats_trigger.sql (360.13µs)19162026/10/01 07:34:46 OK 3_commit_push.sql (209.83µs)19172026/10/01 07:34:46 goose: up to current file version: 319182026/10/01 07:34:46 OK 20251218171726_add_pins.sql (25.22ms)19192026/10/01 07:34:46 OK 20260628120000_add_object_size_and_stats.sql (18.8ms)19202026/10/01 07:34:46 OK 20260905000000_add_claims.sql (32.48ms)19212026/10/01 07:34:46 OK 20260920000000_drop_claims.sql (11.86ms)19222026/10/01 07:34:46 OK 20260923120000_add_pushes.sql (9.27ms)19232026/10/01 07:34:46 goose: successfully migrated database to version: 2026092312000019242026/10/01 07:34:46 OK 1_commit_pending_closure.sql (1.82ms)19252026/10/01 07:34:46 OK 2_object_stats_trigger.sql (354.46µs)19262026/10/01 07:34:46 OK 3_commit_push.sql (579.33µs)19272026/10/01 07:34:46 goose: up to current file version: 319282026-10-01 07:34:46.940 UTC [39462] ERROR: relation "goose_db_version" does not exist at character 3619292026-10-01 07:34:46.940 UTC [39462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1930--- PASS: TestReadProxyRangeRequest (3.03s)1931=== CONT TestReadProxyNarStreaming19322026/10/01 07:34:47 OK 20241026095416_initial_model.sql (126.57ms)19332026-10-01 07:34:47.163 UTC [39483] ERROR: relation "goose_db_version" does not exist at character 3619342026-10-01 07:34:47.163 UTC [39483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19352026/10/01 07:34:47 OK 20251210153512_drop_unused_gin_index.sql (18.92ms)19362026/10/01 07:34:47 OK 20251218171726_add_pins.sql (11.38ms)19372026/10/01 07:34:47 OK 20260628120000_add_object_size_and_stats.sql (32.21ms)19382026/10/01 07:34:47 OK 20260905000000_add_claims.sql (54.7ms)19392026/10/01 07:34:47 OK 20260920000000_drop_claims.sql (14.38ms)19402026/10/01 07:34:47 OK 20260923120000_add_pushes.sql (26.61ms)19412026/10/01 07:34:47 goose: successfully migrated database to version: 2026092312000019422026/10/01 07:34:47 OK 1_commit_pending_closure.sql (2.31ms)19432026/10/01 07:34:47 OK 2_object_stats_trigger.sql (382.13µs)19442026/10/01 07:34:47 OK 3_commit_push.sql (339.71µs)19452026/10/01 07:34:47 goose: up to current file version: 319462026/10/01 07:34:47 OK 20241026095416_initial_model.sql (90.45ms)19472026/10/01 07:34:47 OK 20251210153512_drop_unused_gin_index.sql (10.41ms)1948--- PASS: TestReadRedirectNar (3.11s)1949=== CONT TestReadProxyNarinfoAlreadyDecompressed19502026/10/01 07:34:47 OK 20251218171726_add_pins.sql (48.96ms)19512026/10/01 07:34:47 OK 20260628120000_add_object_size_and_stats.sql (41.23ms)19522026/10/01 07:34:47 OK 20260905000000_add_claims.sql (61.92ms)19532026/10/01 07:34:47 OK 20260920000000_drop_claims.sql (20.6ms)19542026/10/01 07:34:47 OK 20260923120000_add_pushes.sql (16.85ms)19552026/10/01 07:34:47 goose: successfully migrated database to version: 2026092312000019562026/10/01 07:34:47 OK 1_commit_pending_closure.sql (3.07ms)19572026/10/01 07:34:47 OK 2_object_stats_trigger.sql (835.33µs)19582026/10/01 07:34:47 OK 3_commit_push.sql (607.21µs)19592026/10/01 07:34:47 goose: up to current file version: 319602026-10-01 07:34:47.651 UTC [39565] ERROR: relation "goose_db_version" does not exist at character 3619612026-10-01 07:34:47.651 UTC [39565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1962--- PASS: TestReadProxyDisabled (3.40s)1963=== CONT TestReadProxyNarinfo19642026/10/01 07:34:47 OK 20241026095416_initial_model.sql (121.39ms)19652026/10/01 07:34:47 OK 20251210153512_drop_unused_gin_index.sql (56.95ms)19662026/10/01 07:34:47 OK 20251218171726_add_pins.sql (38.46ms)19672026/10/01 07:34:47 OK 20260628120000_add_object_size_and_stats.sql (33.49ms)19682026/10/01 07:34:48 OK 20260905000000_add_claims.sql (45.61ms)19692026/10/01 07:34:48 OK 20260920000000_drop_claims.sql (54.96ms)19702026-10-01 07:34:48.067 UTC [39626] ERROR: relation "goose_db_version" does not exist at character 3619712026-10-01 07:34:48.067 UTC [39626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19722026/10/01 07:34:48 OK 20260923120000_add_pushes.sql (14.34ms)19732026/10/01 07:34:48 goose: successfully migrated database to version: 2026092312000019742026/10/01 07:34:48 OK 1_commit_pending_closure.sql (2.51ms)19752026/10/01 07:34:48 OK 2_object_stats_trigger.sql (621.04µs)19762026/10/01 07:34:48 OK 3_commit_push.sql (1.51ms)19772026/10/01 07:34:48 goose: up to current file version: 31978--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.44s)1979=== CONT TestIsValidCachePath1980=== RUN TestIsValidCachePath/narinfo1981=== PAUSE TestIsValidCachePath/narinfo1982=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1983=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1984=== RUN TestIsValidCachePath/nar_zst1985=== PAUSE TestIsValidCachePath/nar_zst1986=== RUN TestIsValidCachePath/nar_xz1987=== PAUSE TestIsValidCachePath/nar_xz1988=== RUN TestIsValidCachePath/nar_bz21989=== PAUSE TestIsValidCachePath/nar_bz21990=== RUN TestIsValidCachePath/nar_uncompressed1991=== PAUSE TestIsValidCachePath/nar_uncompressed1992=== RUN TestIsValidCachePath/ls1993=== PAUSE TestIsValidCachePath/ls1994=== RUN TestIsValidCachePath/log1995=== PAUSE TestIsValidCachePath/log1996=== RUN TestIsValidCachePath/realisation1997=== PAUSE TestIsValidCachePath/realisation1998=== RUN TestIsValidCachePath/nix-cache-info1999=== PAUSE TestIsValidCachePath/nix-cache-info2000=== RUN TestIsValidCachePath/index.html2001=== PAUSE TestIsValidCachePath/index.html2002=== RUN TestIsValidCachePath/traversal_parent2003=== PAUSE TestIsValidCachePath/traversal_parent2004=== RUN TestIsValidCachePath/traversal_in_middle2005=== PAUSE TestIsValidCachePath/traversal_in_middle2006=== RUN TestIsValidCachePath/invalid_char_e2007=== PAUSE TestIsValidCachePath/invalid_char_e2008=== RUN TestIsValidCachePath/invalid_char_u2009=== PAUSE TestIsValidCachePath/invalid_char_u2010=== RUN TestIsValidCachePath/random_path2011=== PAUSE TestIsValidCachePath/random_path2012=== RUN TestIsValidCachePath/empty2013=== PAUSE TestIsValidCachePath/empty2014=== RUN TestIsValidCachePath/leading_slash2015=== PAUSE TestIsValidCachePath/leading_slash2016=== RUN TestIsValidCachePath/wrong_extension2017=== PAUSE TestIsValidCachePath/wrong_extension2018=== RUN TestIsValidCachePath/short_hash2019=== PAUSE TestIsValidCachePath/short_hash2020=== CONT TestClientFallsBackToClosures20212026/10/01 07:34:48 OK 20241026095416_initial_model.sql (146.52ms)20222026/10/01 07:34:48 OK 20251210153512_drop_unused_gin_index.sql (10.53ms)20232026/10/01 07:34:48 OK 20251218171726_add_pins.sql (20.26ms)20242026-10-01 07:34:48.316 UTC [39642] ERROR: relation "goose_db_version" does not exist at character 3620252026-10-01 07:34:48.316 UTC [39642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20262026/10/01 07:34:48 OK 20260628120000_add_object_size_and_stats.sql (41.45ms)20272026/10/01 07:34:48 OK 20260905000000_add_claims.sql (44.4ms)20282026/10/01 07:34:48 OK 20260920000000_drop_claims.sql (20.04ms)20292026/10/01 07:34:48 OK 20260923120000_add_pushes.sql (35.59ms)20302026/10/01 07:34:48 goose: successfully migrated database to version: 2026092312000020312026/10/01 07:34:48 OK 1_commit_pending_closure.sql (1.34ms)20322026/10/01 07:34:48 OK 2_object_stats_trigger.sql (395.08µs)20332026/10/01 07:34:48 OK 3_commit_push.sql (273.54µs)20342026/10/01 07:34:48 goose: up to current file version: 320352026/10/01 07:34:48 OK 20241026095416_initial_model.sql (143.19ms)20362026/10/01 07:34:48 OK 20251210153512_drop_unused_gin_index.sql (9.6ms)20372026-10-01 07:34:48.538 UTC [39680] ERROR: relation "goose_db_version" does not exist at character 3620382026-10-01 07:34:48.538 UTC [39680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20392026/10/01 07:34:48 OK 20251218171726_add_pins.sql (27.45ms)20402026/10/01 07:34:48 OK 20260628120000_add_object_size_and_stats.sql (35.52ms)2041--- PASS: TestReadProxyConditionalGet (3.47s)2042=== CONT TestClientPushesUseOnePush20432026/10/01 07:34:48 OK 20260905000000_add_claims.sql (59.73ms)20442026/10/01 07:34:48 OK 20260920000000_drop_claims.sql (25.12ms)20452026/10/01 07:34:48 OK 20260923120000_add_pushes.sql (14.56ms)20462026/10/01 07:34:48 goose: successfully migrated database to version: 2026092312000020472026/10/01 07:34:48 OK 1_commit_pending_closure.sql (5.32ms)20482026/10/01 07:34:48 OK 2_object_stats_trigger.sql (4.28ms)20492026/10/01 07:34:48 OK 3_commit_push.sql (1.83ms)20502026/10/01 07:34:48 goose: up to current file version: 320512026/10/01 07:34:48 OK 20241026095416_initial_model.sql (153.2ms)20522026/10/01 07:34:48 OK 20251210153512_drop_unused_gin_index.sql (17.16ms)20532026/10/01 07:34:48 OK 20251218171726_add_pins.sql (15ms)20542026/10/01 07:34:48 OK 20260628120000_add_object_size_and_stats.sql (34.59ms)20552026/10/01 07:34:48 OK 20260905000000_add_claims.sql (24.65ms)20562026/10/01 07:34:48 OK 20260920000000_drop_claims.sql (60.95ms)20572026-10-01 07:34:48.900 UTC [39786] ERROR: relation "goose_db_version" does not exist at character 3620582026-10-01 07:34:48.900 UTC [39786] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20592026/10/01 07:34:48 OK 20260923120000_add_pushes.sql (12.39ms)20602026/10/01 07:34:48 goose: successfully migrated database to version: 2026092312000020612026/10/01 07:34:48 OK 1_commit_pending_closure.sql (3.38ms)20622026/10/01 07:34:48 OK 2_object_stats_trigger.sql (581.5µs)20632026/10/01 07:34:48 OK 3_commit_push.sql (607.21µs)20642026/10/01 07:34:48 goose: up to current file version: 32065--- PASS: TestReadProxyHead (3.61s)2066=== CONT TestPinProtectsFromGC20672026/10/01 07:34:49 OK 20241026095416_initial_model.sql (131.82ms)20682026/10/01 07:34:49 OK 20251210153512_drop_unused_gin_index.sql (14.88ms)20692026/10/01 07:34:49 OK 20251218171726_add_pins.sql (17.63ms)20702026-10-01 07:34:49.128 UTC [39821] ERROR: relation "goose_db_version" does not exist at character 3620712026-10-01 07:34:49.128 UTC [39821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20722026/10/01 07:34:49 OK 20260628120000_add_object_size_and_stats.sql (20.54ms)20732026/10/01 07:34:49 OK 20260905000000_add_claims.sql (18.41ms)20742026/10/01 07:34:49 OK 20260920000000_drop_claims.sql (14.84ms)20752026/10/01 07:34:49 OK 20260923120000_add_pushes.sql (13.15ms)20762026/10/01 07:34:49 goose: successfully migrated database to version: 2026092312000020772026/10/01 07:34:49 OK 1_commit_pending_closure.sql (2.82ms)20782026/10/01 07:34:49 OK 2_object_stats_trigger.sql (602.13µs)20792026/10/01 07:34:49 OK 3_commit_push.sql (434µs)20802026/10/01 07:34:49 goose: up to current file version: 320812026/10/01 07:34:49 OK 20241026095416_initial_model.sql (79.92ms)20822026/10/01 07:34:49 OK 20251210153512_drop_unused_gin_index.sql (23.65ms)20832026/10/01 07:34:49 OK 20251218171726_add_pins.sql (37.22ms)2084--- PASS: TestReadProxyInvalidPath (3.47s)2085=== CONT TestClientSharedPathCommittedMidPush20862026/10/01 07:34:49 OK 20260628120000_add_object_size_and_stats.sql (27.27ms)20872026-10-01 07:34:49.386 UTC [39844] ERROR: relation "goose_db_version" does not exist at character 3620882026-10-01 07:34:49.386 UTC [39844] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20892026/10/01 07:34:49 OK 20260905000000_add_claims.sql (46.19ms)20902026/10/01 07:34:49 OK 20260920000000_drop_claims.sql (14.41ms)20912026/10/01 07:34:49 OK 20260923120000_add_pushes.sql (5.39ms)20922026/10/01 07:34:49 goose: successfully migrated database to version: 2026092312000020932026/10/01 07:34:49 OK 1_commit_pending_closure.sql (2.17ms)20942026/10/01 07:34:49 OK 2_object_stats_trigger.sql (986.33µs)20952026/10/01 07:34:49 OK 3_commit_push.sql (1.63ms)20962026/10/01 07:34:49 goose: up to current file version: 320972026/10/01 07:34:49 OK 20241026095416_initial_model.sql (52.75ms)20982026/10/01 07:34:49 OK 20251210153512_drop_unused_gin_index.sql (5.73ms)20992026/10/01 07:34:49 OK 20251218171726_add_pins.sql (9.1ms)21002026/10/01 07:34:49 OK 20260628120000_add_object_size_and_stats.sql (22.05ms)21012026/10/01 07:34:49 OK 20260905000000_add_claims.sql (25.06ms)21022026/10/01 07:34:49 OK 20260920000000_drop_claims.sql (15.41ms)21032026/10/01 07:34:49 OK 20260923120000_add_pushes.sql (2.8ms)21042026/10/01 07:34:49 goose: successfully migrated database to version: 2026092312000021052026/10/01 07:34:49 OK 1_commit_pending_closure.sql (1.23ms)21062026/10/01 07:34:49 OK 2_object_stats_trigger.sql (506µs)21072026/10/01 07:34:49 OK 3_commit_push.sql (383.67µs)21082026/10/01 07:34:49 goose: up to current file version: 321092026-10-01 07:34:49.610 UTC [39857] ERROR: relation "goose_db_version" does not exist at character 3621102026-10-01 07:34:49.610 UTC [39857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21112026/10/01 07:34:49 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21122026/10/01 07:34:49 WARN mTLS auth: bound subjects configured but subject DN unavailable21132026/10/01 07:34:49 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2114--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.72s)2115=== CONT TestClientWithDependencies21162026/10/01 07:34:49 OK 20241026095416_initial_model.sql (73.51ms)21172026/10/01 07:34:49 OK 20251210153512_drop_unused_gin_index.sql (6.85ms)21182026-10-01 07:34:49.728 UTC [39871] ERROR: relation "goose_db_version" does not exist at character 3621192026-10-01 07:34:49.728 UTC [39871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21202026/10/01 07:34:49 OK 20251218171726_add_pins.sql (14.12ms)21212026/10/01 07:34:49 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)21222026/10/01 07:34:49 OK 20260905000000_add_claims.sql (16.14ms)21232026/10/01 07:34:49 OK 20260920000000_drop_claims.sql (10.86ms)21242026/10/01 07:34:49 OK 20260923120000_add_pushes.sql (4.16ms)21252026/10/01 07:34:49 goose: successfully migrated database to version: 2026092312000021262026/10/01 07:34:49 OK 1_commit_pending_closure.sql (1.85ms)21272026/10/01 07:34:49 OK 2_object_stats_trigger.sql (665.71µs)21282026/10/01 07:34:49 OK 3_commit_push.sql (698.96µs)21292026/10/01 07:34:49 goose: up to current file version: 321302026/10/01 07:34:49 OK 20241026095416_initial_model.sql (44.97ms)21312026/10/01 07:34:49 OK 20251210153512_drop_unused_gin_index.sql (13.73ms)21322026/10/01 07:34:49 OK 20251218171726_add_pins.sql (7.18ms)2133--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.63s)2134=== CONT TestOrphanedObjectsGCStressTest21352026/10/01 07:34:49 OK 20260628120000_add_object_size_and_stats.sql (27.83ms)21362026/10/01 07:34:49 OK 20260905000000_add_claims.sql (25.04ms)21372026/10/01 07:34:49 OK 20260920000000_drop_claims.sql (19.56ms)21382026/10/01 07:34:49 OK 20260923120000_add_pushes.sql (5.8ms)21392026/10/01 07:34:49 goose: successfully migrated database to version: 2026092312000021402026/10/01 07:34:49 OK 1_commit_pending_closure.sql (1.88ms)21412026/10/01 07:34:49 OK 2_object_stats_trigger.sql (984.5µs)21422026/10/01 07:34:49 OK 3_commit_push.sql (510.21µs)21432026/10/01 07:34:49 goose: up to current file version: 321442026-10-01 07:34:50.104 UTC [39909] ERROR: relation "goose_db_version" does not exist at character 3621452026-10-01 07:34:50.104 UTC [39909] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21462026/10/01 07:34:50 INFO Starting HTTP server address=/nix/var/nix/builds/nix-37277-823233434/TestProxyHeadersOnlyTrustedOnSocket3972658002/001/proxy.sock21472026/10/01 07:34:50 INFO Starting HTTP server address=127.0.0.1:5554921482026/10/01 07:34:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"21492026/10/01 07:34:50 INFO Shutdown signal received, draining in-flight requests timeout=10s2150--- PASS: TestProxyHeadersOnlyTrustedOnSocket (3.51s)2151=== CONT TestOrphanedObjectsGC21522026/10/01 07:34:50 OK 20241026095416_initial_model.sql (107.45ms)21532026/10/01 07:34:50 OK 20251210153512_drop_unused_gin_index.sql (46.14ms)21542026/10/01 07:34:50 OK 20251218171726_add_pins.sql (57.24ms)21552026/10/01 07:34:50 OK 20260628120000_add_object_size_and_stats.sql (25.25ms)21562026/10/01 07:34:50 OK 20260905000000_add_claims.sql (15.71ms)21572026/10/01 07:34:50 OK 20260920000000_drop_claims.sql (20.8ms)21582026/10/01 07:34:50 OK 20260923120000_add_pushes.sql (7.1ms)21592026/10/01 07:34:50 goose: successfully migrated database to version: 2026092312000021602026/10/01 07:34:50 OK 1_commit_pending_closure.sql (3.21ms)21612026/10/01 07:34:50 OK 2_object_stats_trigger.sql (505.58µs)21622026/10/01 07:34:50 OK 3_commit_push.sql (444.08µs)21632026/10/01 07:34:50 goose: up to current file version: 32164--- PASS: TestReadProxyNarStreaming (3.50s)2165=== CONT TestCreatePin_ReservedPins21662026-10-01 07:34:50.567 UTC [39951] ERROR: relation "goose_db_version" does not exist at character 3621672026-10-01 07:34:50.567 UTC [39951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21682026/10/01 07:34:50 OK 20241026095416_initial_model.sql (26.45ms)21692026/10/01 07:34:50 OK 20251210153512_drop_unused_gin_index.sql (9.1ms)21702026/10/01 07:34:50 OK 20251218171726_add_pins.sql (15.86ms)21712026/10/01 07:34:50 OK 20260628120000_add_object_size_and_stats.sql (17.17ms)21722026/10/01 07:34:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55560/oidc21732026/10/01 07:34:50 OK 20260905000000_add_claims.sql (13.51ms)21742026/10/01 07:34:50 OK 20260920000000_drop_claims.sql (13.18ms)21752026-10-01 07:34:50.692 UTC [39967] ERROR: relation "goose_db_version" does not exist at character 3621762026-10-01 07:34:50.692 UTC [39967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21772026/10/01 07:34:50 OK 20260923120000_add_pushes.sql (3.12ms)21782026/10/01 07:34:50 goose: successfully migrated database to version: 2026092312000021792026/10/01 07:34:50 OK 1_commit_pending_closure.sql (2.14ms)21802026/10/01 07:34:50 OK 2_object_stats_trigger.sql (685.71µs)21812026/10/01 07:34:50 OK 3_commit_push.sql (447.79µs)21822026/10/01 07:34:50 goose: up to current file version: 32183--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.35s)2184=== CONT TestParseSingleRange2185=== RUN TestParseSingleRange/none2186=== PAUSE TestParseSingleRange/none2187=== RUN TestParseSingleRange/unknown_unit2188=== PAUSE TestParseSingleRange/unknown_unit2189=== RUN TestParseSingleRange/multi-range_ignored2190=== PAUSE TestParseSingleRange/multi-range_ignored2191=== RUN TestParseSingleRange/malformed_no_dash2192=== PAUSE TestParseSingleRange/malformed_no_dash2193=== RUN TestParseSingleRange/malformed_both_empty2194=== PAUSE TestParseSingleRange/malformed_both_empty2195=== RUN TestParseSingleRange/malformed_end_before_start2196=== PAUSE TestParseSingleRange/malformed_end_before_start2197=== RUN TestParseSingleRange/closed2198=== PAUSE TestParseSingleRange/closed2199=== RUN TestParseSingleRange/open-ended2200=== PAUSE TestParseSingleRange/open-ended2201=== RUN TestParseSingleRange/end_clamped_to_size2202=== PAUSE TestParseSingleRange/end_clamped_to_size2203=== RUN TestParseSingleRange/suffix2204=== PAUSE TestParseSingleRange/suffix2205=== RUN TestParseSingleRange/suffix_exceeds_size2206=== PAUSE TestParseSingleRange/suffix_exceeds_size2207=== RUN TestParseSingleRange/single_byte2208=== PAUSE TestParseSingleRange/single_byte2209=== RUN TestParseSingleRange/start_past_EOF2210=== PAUSE TestParseSingleRange/start_past_EOF2211=== RUN TestParseSingleRange/start_far_past_EOF2212=== PAUSE TestParseSingleRange/start_far_past_EOF2213=== CONT TestObjectStatsTrigger22142026/10/01 07:34:50 OK 20241026095416_initial_model.sql (73.8ms)22152026/10/01 07:34:50 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)22162026/10/01 07:34:50 OK 20251218171726_add_pins.sql (12.73ms)22172026/10/01 07:34:50 OK 20260628120000_add_object_size_and_stats.sql (14.51ms)22182026/10/01 07:34:50 OK 20260905000000_add_claims.sql (36.68ms)22192026/10/01 07:34:50 OK 20260920000000_drop_claims.sql (6.97ms)22202026/10/01 07:34:50 OK 20260923120000_add_pushes.sql (6.32ms)22212026/10/01 07:34:50 goose: successfully migrated database to version: 2026092312000022222026/10/01 07:34:50 OK 1_commit_pending_closure.sql (2.04ms)22232026/10/01 07:34:50 OK 2_object_stats_trigger.sql (286.25µs)22242026/10/01 07:34:50 OK 3_commit_push.sql (181.63µs)22252026/10/01 07:34:50 goose: up to current file version: 32226--- PASS: TestReadProxyNarinfo (3.23s)2227=== CONT TestResolveDBConnectionString2228=== RUN TestResolveDBConnectionString/flag_wins2229=== PAUSE TestResolveDBConnectionString/flag_wins2230=== RUN TestResolveDBConnectionString/file_when_flag_empty2231=== PAUSE TestResolveDBConnectionString/file_when_flag_empty2232=== RUN TestResolveDBConnectionString/missing_file_is_an_error2233=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error2234=== RUN TestResolveDBConnectionString/PGHOST_allows_empty2235=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty2236=== RUN TestResolveDBConnectionString/nothing_configured2237=== PAUSE TestResolveDBConnectionString/nothing_configured2238=== CONT TestClientErrorHandling/InvalidStorePath22392026-10-01 07:34:51.490 UTC [40016] ERROR: relation "goose_db_version" does not exist at character 3622402026-10-01 07:34:51.490 UTC [40016] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22412026/10/01 07:34:51 OK 20241026095416_initial_model.sql (96.83ms)22422026/10/01 07:34:51 OK 20251210153512_drop_unused_gin_index.sql (14.22ms)22432026-10-01 07:34:51.659 UTC [40025] ERROR: relation "goose_db_version" does not exist at character 3622442026-10-01 07:34:51.659 UTC [40025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22452026/10/01 07:34:51 OK 20251218171726_add_pins.sql (36.76ms)22462026/10/01 07:34:51 OK 20260628120000_add_object_size_and_stats.sql (26.07ms)22472026/10/01 07:34:51 INFO Received uploads request method=POST path=/api/pending_closures22482026/10/01 07:34:51 INFO Received uploads request method=POST path=/api/pending_closures22492026/10/01 07:34:51 OK 20260905000000_add_claims.sql (71.82ms)22502026-10-01 07:34:51.776 UTC [40031] ERROR: relation "goose_db_version" does not exist at character 3622512026-10-01 07:34:51.776 UTC [40031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22522026/10/01 07:34:51 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22532026/10/01 07:34:51 INFO Uploading nglhv0ljb9mv13ylr0hqw8r1wzdyf6si-a (248B)22542026/10/01 07:34:51 INFO Uploading ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb-shared-dep (136B)22552026/10/01 07:34:51 OK 20241026095416_initial_model.sql (63.49ms)22562026/10/01 07:34:51 OK 20260920000000_drop_claims.sql (23.93ms)22572026/10/01 07:34:51 OK 20251210153512_drop_unused_gin_index.sql (35.76ms)22582026/10/01 07:34:51 OK 20260923120000_add_pushes.sql (35.38ms)22592026/10/01 07:34:51 goose: successfully migrated database to version: 2026092312000022602026/10/01 07:34:51 OK 20251218171726_add_pins.sql (18.92ms)22612026/10/01 07:34:51 OK 1_commit_pending_closure.sql (13.81ms)22622026/10/01 07:34:51 OK 2_object_stats_trigger.sql (2.08ms)22632026/10/01 07:34:51 OK 20260628120000_add_object_size_and_stats.sql (8.66ms)22642026/10/01 07:34:51 OK 3_commit_push.sql (7.92ms)22652026/10/01 07:34:51 goose: up to current file version: 322662026/10/01 07:34:51 OK 20241026095416_initial_model.sql (25.92ms)22672026/10/01 07:34:51 WARN Failed to register uploaded object key=ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb.ls error="server returned 404: 404 page not found\n"22682026/10/01 07:34:51 WARN Failed to register uploaded object key=6fkxqwkismk7rw2sz730wa6zlh79zcnr.ls error="server returned 404: 404 page not found\n"22692026/10/01 07:34:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22702026/10/01 07:34:51 OK 20260905000000_add_claims.sql (20.44ms)22712026/10/01 07:34:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22722026/10/01 07:34:51 WARN Failed to register uploaded object key=nar/09svwm91qpj2v6w03ppsh59gl0wvf2xvddq5kmh1ld0y06lvlj1z.nar.zst error="server returned 404: 404 page not found\n"22732026/10/01 07:34:51 WARN Failed to register uploaded object key=nglhv0ljb9mv13ylr0hqw8r1wzdyf6si.ls error="server returned 404: 404 page not found\n"22742026/10/01 07:34:51 INFO Signed narinfos id=1 count=222752026/10/01 07:34:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22762026/10/01 07:34:51 INFO Signed narinfos id=2 count=222772026/10/01 07:34:51 INFO Uploading 4 narinfos22782026/10/01 07:34:51 OK 20251210153512_drop_unused_gin_index.sql (23.21ms)22792026/10/01 07:34:51 OK 20260920000000_drop_claims.sql (16.84ms)22802026/10/01 07:34:51 OK 20260923120000_add_pushes.sql (2.24ms)22812026/10/01 07:34:51 goose: successfully migrated database to version: 2026092312000022822026/10/01 07:34:51 OK 20251218171726_add_pins.sql (13.35ms)22832026/10/01 07:34:51 WARN Failed to register uploaded object key=ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb.narinfo error="server returned 404: 404 page not found\n"22842026/10/01 07:34:51 WARN Failed to register uploaded object key=nglhv0ljb9mv13ylr0hqw8r1wzdyf6si.narinfo error="server returned 404: 404 page not found\n"22852026/10/01 07:34:51 OK 1_commit_pending_closure.sql (2.2ms)22862026/10/01 07:34:51 OK 2_object_stats_trigger.sql (278.33µs)22872026/10/01 07:34:51 OK 3_commit_push.sql (177.46µs)22882026/10/01 07:34:51 goose: up to current file version: 322892026/10/01 07:34:51 WARN Failed to register uploaded object key=6fkxqwkismk7rw2sz730wa6zlh79zcnr.narinfo error="server returned 404: 404 page not found\n"22902026/10/01 07:34:51 OK 20260628120000_add_object_size_and_stats.sql (29.05ms)2291=== NAME TestPinProtectsFromGC2292 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-37277-823233434/TestPinProtectsFromGC1153529923/001/store/75rnfk00w00k7fhqyj1fz4f6nyhw9v4y-pinned-file.txt2293 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-37277-823233434/TestPinProtectsFromGC1153529923/001/store/lm7fqzb8d2fi4h8hr1vwqy8mhpgq17aq-unpinned-file.txt22942026/10/01 07:34:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22952026/10/01 07:34:51 WARN Failed to register uploaded object key=ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb.narinfo error="server returned 404: 404 page not found\n"22962026/10/01 07:34:51 INFO Completed upload id=122972026/10/01 07:34:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22982026/10/01 07:34:51 INFO Completed upload id=222992026/10/01 07:34:51 INFO Upload complete. (355ms)2300=== NAME TestClientFallsBackToClosures2301 client_pushes_test.go:112: Retrieved narinfo from S3:2302 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientFallsBackToClosures3502179387/001/store/ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb-shared-dep2303 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2304 Compression: zstd2305 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822306 NarSize: 1362307 References: 2308 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2309 client_pushes_test.go:112: Retrieved narinfo from S3:2310 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientFallsBackToClosures3502179387/001/store/nglhv0ljb9mv13ylr0hqw8r1wzdyf6si-a2311 URL: nar/09svwm91qpj2v6w03ppsh59gl0wvf2xvddq5kmh1ld0y06lvlj1z.nar.zst2312 Compression: zstd2313 NarHash: sha256:09svwm91qpj2v6w03ppsh59gl0wvf2xvddq5kmh1ld0y06lvlj1z2314 NarSize: 2482315 References: /nix/var/nix/builds/nix-37277-823233434/TestClientFallsBackToClosures3502179387/001/store/ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb-shared-dep2316 CA: text:sha256:04mzaa5snb67jbv53m9xkssk02l58p47158b2rxl4bprnwhfc41j2317 client_pushes_test.go:112: Retrieved narinfo from S3:2318 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientFallsBackToClosures3502179387/001/store/6fkxqwkismk7rw2sz730wa6zlh79zcnr-b2319 URL: nar/09svwm91qpj2v6w03ppsh59gl0wvf2xvddq5kmh1ld0y06lvlj1z.nar.zst2320 Compression: zstd2321 NarHash: sha256:09svwm91qpj2v6w03ppsh59gl0wvf2xvddq5kmh1ld0y06lvlj1z2322 NarSize: 2482323 References: /nix/var/nix/builds/nix-37277-823233434/TestClientFallsBackToClosures3502179387/001/store/ffx2w1vkn69vjl2dlxs6wkm4y85s6yfb-shared-dep2324 CA: text:sha256:04mzaa5snb67jbv53m9xkssk02l58p47158b2rxl4bprnwhfc41j23252026/10/01 07:34:51 INFO Received push request method=POST path=/api/pushes23262026/10/01 07:34:51 OK 20260905000000_add_claims.sql (51.82ms)23272026/10/01 07:34:51 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)23282026/10/01 07:34:51 INFO Uploading dlgx2ppbmpw46jdy477lwpiy3x7jhq96-shared-dep (136B)23292026/10/01 07:34:51 INFO Uploading iix66wk20a2h274w0grflm7hmwadwcp6-b (248B)23302026/10/01 07:34:52 OK 20260920000000_drop_claims.sql (32.78ms)2331--- PASS: TestClientFallsBackToClosures (3.86s)2332=== CONT TestClientErrorHandling/ServerNotAvailable23332026/10/01 07:34:52 OK 20260923120000_add_pushes.sql (15.77ms)23342026/10/01 07:34:52 goose: successfully migrated database to version: 2026092312000023352026/10/01 07:34:52 OK 1_commit_pending_closure.sql (4.92ms)23362026/10/01 07:34:52 OK 2_object_stats_trigger.sql (1.38ms)23372026/10/01 07:34:52 OK 3_commit_push.sql (539.58µs)23382026/10/01 07:34:52 goose: up to current file version: 323392026/10/01 07:34:52 WARN Failed to register uploaded object key=dlgx2ppbmpw46jdy477lwpiy3x7jhq96.ls error="server returned 404: 404 page not found\n"23402026/10/01 07:34:52 WARN Failed to register uploaded object key=9lca367ipgzkgq748amppv86fgqyh72j.ls error="server returned 404: 404 page not found\n"23412026/10/01 07:34:52 WARN Failed to register uploaded object key=iix66wk20a2h274w0grflm7hmwadwcp6.ls error="server returned 404: 404 page not found\n"23422026/10/01 07:34:52 WARN Failed to register uploaded object key=nar/15nvvlcjdc52yaqjmwxqn30azds5nfvyc9czkpirj9yh8b7g4hvg.nar.zst error="server returned 404: 404 page not found\n"23432026/10/01 07:34:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23442026/10/01 07:34:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23452026/10/01 07:34:52 INFO Signed narinfos id=1 count=323462026/10/01 07:34:52 INFO Uploading 3 narinfos23472026/10/01 07:34:52 WARN Failed to register uploaded object key=iix66wk20a2h274w0grflm7hmwadwcp6.narinfo error="server returned 404: 404 page not found\n"23482026/10/01 07:34:52 WARN Failed to register uploaded object key=dlgx2ppbmpw46jdy477lwpiy3x7jhq96.narinfo error="server returned 404: 404 page not found\n"23492026/10/01 07:34:52 INFO Received complete push request method=POST path=/api/pushes/1/complete23502026/10/01 07:34:52 WARN Failed to register uploaded object key=9lca367ipgzkgq748amppv86fgqyh72j.narinfo error="server returned 404: 404 page not found\n"23512026/10/01 07:34:52 INFO Upload complete. (184ms)2352=== NAME TestClientPushesUseOnePush2353 client_pushes_test.go:97: Retrieved narinfo from S3:2354 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientPushesUseOnePush2247448273/001/store/dlgx2ppbmpw46jdy477lwpiy3x7jhq96-shared-dep2355 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2356 Compression: zstd2357 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822358 NarSize: 1362359 References: 2360 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2361 client_pushes_test.go:97: Retrieved narinfo from S3:2362 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientPushesUseOnePush2247448273/001/store/9lca367ipgzkgq748amppv86fgqyh72j-a2363 URL: nar/15nvvlcjdc52yaqjmwxqn30azds5nfvyc9czkpirj9yh8b7g4hvg.nar.zst2364 Compression: zstd2365 NarHash: sha256:15nvvlcjdc52yaqjmwxqn30azds5nfvyc9czkpirj9yh8b7g4hvg2366 NarSize: 2482367 References: /nix/var/nix/builds/nix-37277-823233434/TestClientPushesUseOnePush2247448273/001/store/dlgx2ppbmpw46jdy477lwpiy3x7jhq96-shared-dep2368 CA: text:sha256:0s9b7amxz690b7q299xvzj8rrv8vzs2w7n2b5rq7g2v9c0ffckk02369 client_pushes_test.go:97: Retrieved narinfo from S3:2370 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientPushesUseOnePush2247448273/001/store/iix66wk20a2h274w0grflm7hmwadwcp6-b2371 URL: nar/15nvvlcjdc52yaqjmwxqn30azds5nfvyc9czkpirj9yh8b7g4hvg.nar.zst2372 Compression: zstd2373 NarHash: sha256:15nvvlcjdc52yaqjmwxqn30azds5nfvyc9czkpirj9yh8b7g4hvg2374 NarSize: 2482375 References: /nix/var/nix/builds/nix-37277-823233434/TestClientPushesUseOnePush2247448273/001/store/dlgx2ppbmpw46jdy477lwpiy3x7jhq96-shared-dep2376 CA: text:sha256:0s9b7amxz690b7q299xvzj8rrv8vzs2w7n2b5rq7g2v9c0ffckk02377--- PASS: TestClientPushesUseOnePush (3.52s)2378=== CONT TestClientErrorHandling/InvalidAuthToken23792026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes23802026/10/01 07:34:52 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23812026/10/01 07:34:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23822026/10/01 07:34:52 INFO Uploading 75rnfk00w00k7fhqyj1fz4f6nyhw9v4y-pinned-file.txt (128B)23832026/10/01 07:34:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"23842026/10/01 07:34:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23852026/10/01 07:34:52 WARN Failed to register uploaded object key=75rnfk00w00k7fhqyj1fz4f6nyhw9v4y.ls error="server returned 404: 404 page not found\n"23862026/10/01 07:34:52 INFO Signed narinfos id=1 count=123872026/10/01 07:34:52 INFO Uploading 1 narinfos23882026/10/01 07:34:52 INFO Received complete push request method=POST path=/api/pushes/1/complete23892026/10/01 07:34:52 WARN Failed to register uploaded object key=75rnfk00w00k7fhqyj1fz4f6nyhw9v4y.narinfo error="server returned 404: 404 page not found\n"23902026/10/01 07:34:52 INFO Upload complete. (159ms)23912026/10/01 07:34:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.641761ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23922026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes23932026/10/01 07:34:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23942026/10/01 07:34:52 INFO Uploading lm7fqzb8d2fi4h8hr1vwqy8mhpgq17aq-unpinned-file.txt (128B)23952026/10/01 07:34:52 WARN Failed to register uploaded object key=lm7fqzb8d2fi4h8hr1vwqy8mhpgq17aq.ls error="server returned 404: 404 page not found\n"23962026/10/01 07:34:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23972026/10/01 07:34:52 INFO Signed narinfos id=2 count=123982026/10/01 07:34:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"23992026/10/01 07:34:52 INFO Uploading 1 narinfos24002026/10/01 07:34:52 INFO Received complete push request method=POST path=/api/pushes/2/complete24012026/10/01 07:34:52 WARN Failed to register uploaded object key=lm7fqzb8d2fi4h8hr1vwqy8mhpgq17aq.narinfo error="server returned 404: 404 page not found\n"24022026/10/01 07:34:52 INFO Upload complete. (118ms)24032026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes24042026/10/01 07:34:52 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)24052026/10/01 07:34:52 INFO Uploading ypxk9y9wxgbvnnaflx9js5mcp04fl1xh-top (256B)24062026/10/01 07:34:52 INFO Uploading 8vhalrpvc34qr5l9j0162fd2r4mh4lmw-shared-dep (136B)24072026/10/01 07:34:52 INFO Received create pin request method=POST path=/api/pins/myapp24082026/10/01 07:34:52 WARN Failed to register uploaded object key=8vhalrpvc34qr5l9j0162fd2r4mh4lmw.ls error="server returned 404: 404 page not found\n"24092026/10/01 07:34:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.024173ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24102026/10/01 07:34:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24112026/10/01 07:34:52 WARN Failed to register uploaded object key=ypxk9y9wxgbvnnaflx9js5mcp04fl1xh.ls error="server returned 404: 404 page not found\n"24122026/10/01 07:34:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24132026/10/01 07:34:52 WARN Failed to register uploaded object key=nar/1rd8z1pp9lcq074a19814mk9avl3aq0xzn82fi8znass232aaph3.nar.zst error="server returned 404: 404 page not found\n"24142026/10/01 07:34:52 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-37277-823233434/TestPinProtectsFromGC1153529923/001/store/75rnfk00w00k7fhqyj1fz4f6nyhw9v4y-pinned-file.txt narinfo_key=75rnfk00w00k7fhqyj1fz4f6nyhw9v4y.narinfo24152026/10/01 07:34:52 INFO Signed narinfos id=1 count=224162026/10/01 07:34:52 INFO Uploading 2 narinfos24172026/10/01 07:34:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures24182026/10/01 07:34:52 INFO Garbage collection started24192026/10/01 07:34:52 INFO Aborted multipart uploads count=024202026/10/01 07:34:52 WARN Force mode enabled - objects will be deleted immediately without grace period24212026/10/01 07:34:52 WARN Failed to register uploaded object key=ypxk9y9wxgbvnnaflx9js5mcp04fl1xh.narinfo error="server returned 404: 404 page not found\n"24222026/10/01 07:34:52 INFO Received complete push request method=POST path=/api/pushes/1/complete24232026/10/01 07:34:52 WARN Failed to register uploaded object key=8vhalrpvc34qr5l9j0162fd2r4mh4lmw.narinfo error="server returned 404: 404 page not found\n"24242026/10/01 07:34:52 INFO Upload complete. (175ms)2425=== NAME TestClientSharedPathCommittedMidPush2426 client_integration_test.go:680: Retrieved narinfo from S3:2427 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientSharedPathCommittedMidPush2776420961/001/store/8vhalrpvc34qr5l9j0162fd2r4mh4lmw-shared-dep2428 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2429 Compression: zstd2430 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822431 NarSize: 1362432 References: 2433 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n24342026/10/01 07:34:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=02435 client_integration_test.go:680: Retrieved narinfo from S3:2436 StorePath: /nix/var/nix/builds/nix-37277-823233434/TestClientSharedPathCommittedMidPush2776420961/001/store/ypxk9y9wxgbvnnaflx9js5mcp04fl1xh-top2437 URL: nar/1rd8z1pp9lcq074a19814mk9avl3aq0xzn82fi8znass232aaph3.nar.zst2438 Compression: zstd2439 NarHash: sha256:1rd8z1pp9lcq074a19814mk9avl3aq0xzn82fi8znass232aaph32440 NarSize: 2562441 References: /nix/var/nix/builds/nix-37277-823233434/TestClientSharedPathCommittedMidPush2776420961/001/store/8vhalrpvc34qr5l9j0162fd2r4mh4lmw-shared-dep2442 CA: text:sha256:1k81k7kqwlxdlvy8cm5j16i3xqlv60z6w2agd67yqw2x35qcifi324432026/10/01 07:34:52 INFO Vacuumed table table=pending_closures24442026/10/01 07:34:52 INFO Vacuumed table table=pending_objects24452026/10/01 07:34:52 INFO Vacuumed table table=multipart_uploads2446--- PASS: TestClientSharedPathCommittedMidPush (3.29s)2447=== CONT TestCacheConfigHandler/full_config,_no_issuer2448=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2449=== CONT TestCacheConfigHandler/no_signing_keys2450=== CONT TestCacheConfigHandler/no_cache_url_configured2451--- PASS: TestCacheConfigHandler (0.00s)2452 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2453 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2454 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2455 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2456=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure24572026/10/01 07:34:52 INFO Received uploads request method=POST path=/24582026/10/01 07:34:52 INFO Vacuumed table table=closures24592026/10/01 07:34:52 INFO Vacuumed table table=objects24602026-10-01 07:34:52.747 UTC [40141] ERROR: relation "goose_db_version" does not exist at character 3624612026-10-01 07:34:52.747 UTC [40141] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24622026/10/01 07:34:52 OK 20241026095416_initial_model.sql (24.73ms)24632026/10/01 07:34:52 OK 20251210153512_drop_unused_gin_index.sql (6.75ms)24642026/10/01 07:34:52 OK 20251218171726_add_pins.sql (11.51ms)24652026/10/01 07:34:52 OK 20260628120000_add_object_size_and_stats.sql (8.84ms)24662026/10/01 07:34:52 OK 20260905000000_add_claims.sql (26.07ms)24672026/10/01 07:34:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24682026/10/01 07:34:52 WARN Refused reserved pin name=worker-x86_64-linux24692026/10/01 07:34:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24702026/10/01 07:34:52 INFO Received create pin request method=POST path=/api/pins/my-app24712026/10/01 07:34:52 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2472--- PASS: TestCreatePin_ReservedPins (2.40s)2473=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24742026/10/01 07:34:52 INFO Received request for more parts method=POST path=/24752026/10/01 07:34:52 OK 20260920000000_drop_claims.sql (29.86ms)24762026/10/01 07:34:52 OK 20260923120000_add_pushes.sql (12.44ms)24772026/10/01 07:34:52 goose: successfully migrated database to version: 2026092312000024782026/10/01 07:34:52 OK 1_commit_pending_closure.sql (2.04ms)24792026/10/01 07:34:52 OK 2_object_stats_trigger.sql (2.82ms)24802026/10/01 07:34:52 OK 3_commit_push.sql (2.11ms)24812026/10/01 07:34:52 goose: up to current file version: 32482=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart24832026/10/01 07:34:52 INFO Received complete multipart upload request method=POST path=/2484=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info24852026/10/01 07:34:52 INFO Received uploads request method=POST path=/2486=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key24872026/10/01 07:34:52 INFO Received complete multipart upload request method=POST path=/24882026/10/01 07:34:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=729.766971ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2489=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key24902026/10/01 07:34:52 INFO Received request for more parts method=POST path=/2491=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal24922026/10/01 07:34:52 INFO Received uploads request method=POST path=/2493--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2494 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2495 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2496 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2497 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2498=== CONT TestIsValidUploadKey/narinfo2499=== CONT TestIsValidUploadKey/realisation_plus_in_output2500=== CONT TestIsValidUploadKey/unknown_type2501=== CONT TestIsValidUploadKey/empty_key2502=== CONT TestIsValidUploadKey/absolute2503=== CONT TestIsValidUploadKey/traversal_nar2504=== CONT TestIsValidUploadKey/traversal2505=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2506=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2507=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2508=== CONT TestIsValidUploadKey/index.html2509=== CONT TestIsValidUploadKey/nix-cache-info2510=== CONT TestIsValidUploadKey/build_log_home-manager_file2511=== CONT TestIsValidUploadKey/realisation2512=== CONT TestIsValidUploadKey/build_log_equals2513=== CONT TestIsValidUploadKey/build_log_question_mark2514=== CONT TestIsValidUploadKey/build_log_plus_in_name2515=== CONT TestIsValidUploadKey/nar_plain2516=== CONT TestIsValidUploadKey/build_log2517=== CONT TestIsValidUploadKey/listing2518=== CONT TestIsValidUploadKey/nar_zst2519=== CONT TestIsValidUploadKey/nar_xz2520--- PASS: TestIsValidUploadKey (0.00s)2521 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2522 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2523 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2524 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2525 --- PASS: TestIsValidUploadKey/absolute (0.00s)2526 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2527 --- PASS: TestIsValidUploadKey/traversal (0.00s)2528 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2529 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2530 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2531 --- PASS: TestIsValidUploadKey/index.html (0.00s)2532 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2533 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2534 --- PASS: TestIsValidUploadKey/realisation (0.00s)2535 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2536 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2537 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2538 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2539 --- PASS: TestIsValidUploadKey/build_log (0.00s)2540 --- PASS: TestIsValidUploadKey/listing (0.00s)2541 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2542 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2543=== CONT TestProxyWriteTimeout/narinfo2544=== CONT TestProxyWriteTimeout/10_GiB_nar2545=== CONT TestProxyWriteTimeout/unknown_size2546=== CONT TestProxyWriteTimeout/1_GiB_nar2547--- PASS: TestProxyWriteTimeout (0.00s)2548 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2549 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2550 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2551 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2552=== CONT TestPush_RejectsBadRequests/no_roots25532026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes2554=== CONT TestPush_RejectsBadRequests/bad_root25552026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes2556=== CONT TestPush_RejectsBadRequests/root_not_in_objects25572026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes2558=== CONT TestPush_RejectsBadRequests/no_objects25592026/10/01 07:34:52 INFO Received push request method=POST path=/api/pushes2560=== CONT TestService_RequireScope_OIDC/builder_may_write2561--- PASS: TestPush_RejectsBadRequests (3.53s)2562 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2563 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2564 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2565 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2566=== CONT TestService_RequireScope_OIDC/static_token_may_admin2567=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2568=== CONT TestService_RequireScope_OIDC/writer_implies_read2569=== CONT TestService_RequireScope_OIDC/reader_may_read2570=== CONT TestService_RequireScope_OIDC/static_token_may_write2571=== CONT TestService_RequireScope_OIDC/ops_may_not_write2572=== CONT TestService_RequireScope_OIDC/reader_may_not_write2573=== CONT TestService_RequireScope_OIDC/ops_may_admin2574=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2575=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2576--- PASS: TestService_RequireScope_OIDC (2.73s)2577 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2578 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2579 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2580 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2581 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2582 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2583 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2584 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2585 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2586 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2587=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected25882026/10/01 07:34:52 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]2589=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2590=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected25912026/10/01 07:34:52 WARN Authentication failed token_preview=eyJhbGciOi...c7l5ACuwjg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2592=== CONT TestIsValidCachePath/narinfo2593=== CONT TestIsValidCachePath/index.html2594=== CONT TestIsValidCachePath/short_hash2595=== CONT TestIsValidCachePath/wrong_extension2596=== CONT TestIsValidCachePath/leading_slash2597=== CONT TestIsValidCachePath/empty2598=== CONT TestIsValidCachePath/random_path2599=== CONT TestIsValidCachePath/invalid_char_u2600=== CONT TestIsValidCachePath/invalid_char_e2601=== CONT TestIsValidCachePath/traversal_in_middle2602=== CONT TestIsValidCachePath/traversal_parent2603=== CONT TestIsValidCachePath/nar_uncompressed2604=== CONT TestIsValidCachePath/nix-cache-info2605=== CONT TestIsValidCachePath/realisation2606=== CONT TestIsValidCachePath/log2607=== CONT TestIsValidCachePath/ls2608=== CONT TestIsValidCachePath/nar_xz2609=== CONT TestIsValidCachePath/nar_bz22610=== CONT TestIsValidCachePath/nar_zst2611=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2612--- PASS: TestIsValidCachePath (0.00s)2613 --- PASS: TestIsValidCachePath/narinfo (0.00s)2614 --- PASS: TestIsValidCachePath/index.html (0.00s)2615 --- PASS: TestIsValidCachePath/short_hash (0.00s)2616 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2617 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2618 --- PASS: TestIsValidCachePath/empty (0.00s)2619 --- PASS: TestIsValidCachePath/random_path (0.00s)2620 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2621 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2622 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2623 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2624 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2625 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2626 --- PASS: TestIsValidCachePath/realisation (0.00s)2627 --- PASS: TestIsValidCachePath/log (0.00s)2628 --- PASS: TestIsValidCachePath/ls (0.00s)2629 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2630 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2631 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2632 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2633=== CONT TestParseSingleRange/none2634=== CONT TestParseSingleRange/open-ended2635=== CONT TestParseSingleRange/start_far_past_EOF2636=== CONT TestParseSingleRange/start_past_EOF2637=== CONT TestParseSingleRange/single_byte2638=== CONT TestParseSingleRange/end_clamped_to_size2639=== CONT TestParseSingleRange/suffix2640=== CONT TestParseSingleRange/suffix_exceeds_size2641=== CONT TestParseSingleRange/malformed_both_empty2642=== CONT TestParseSingleRange/closed2643=== CONT TestParseSingleRange/malformed_end_before_start2644=== CONT TestParseSingleRange/multi-range_ignored2645=== CONT TestParseSingleRange/unknown_unit2646=== CONT TestParseSingleRange/malformed_no_dash2647--- PASS: TestParseSingleRange (0.00s)2648 --- PASS: TestParseSingleRange/none (0.00s)2649 --- PASS: TestParseSingleRange/open-ended (0.00s)2650 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2651 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2652 --- PASS: TestParseSingleRange/single_byte (0.00s)2653 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2654 --- PASS: TestParseSingleRange/suffix (0.00s)2655 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2656 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2657 --- PASS: TestParseSingleRange/closed (0.00s)2658 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2659 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2660 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2661 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2662=== CONT TestResolveDBConnectionString/flag_wins2663=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2664=== CONT TestResolveDBConnectionString/nothing_configured2665=== CONT TestResolveDBConnectionString/missing_file_is_an_error2666=== CONT TestResolveDBConnectionString/file_when_flag_empty2667--- PASS: TestResolveDBConnectionString (0.01s)2668 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2669 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2670 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2671 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2672 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2673--- PASS: TestService_AuthMiddleware_OIDC (2.94s)2674 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2675 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2676 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2677 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2678--- PASS: TestObjectStatsTrigger (2.40s)2679=== NAME TestClientWithDependencies2680 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-37277-823233434/TestClientWithDependencies3572692299/001/store/axbmhzn6z302xs1dzrsh8plkc0hn2l5h-test-script2681 client_integration_test.go:615: Found 1 dependencies (including self)2682=== NAME TestOrphanedObjectsGC2683 orphaned_objects_gc_test.go:290: GC Test Summary:2684 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2685 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2686 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2687 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2688 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2689--- PASS: TestOrphanedObjectsGC (3.12s)26902026/10/01 07:34:53 INFO Received push request method=POST path=/api/pushes26912026/10/01 07:34:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26922026/10/01 07:34:53 INFO Uploading axbmhzn6z302xs1dzrsh8plkc0hn2l5h-test-script (136B)26932026/10/01 07:34:53 WARN Failed to register uploaded object key=axbmhzn6z302xs1dzrsh8plkc0hn2l5h.ls error="server returned 404: 404 page not found\n"26942026/10/01 07:34:53 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"26952026/10/01 07:34:53 WARN Failed to register uploaded object key=log/3pmhwbzb68jrn98hgmdchq562hks9rf1-test-script.drv error="server returned 404: 404 page not found\n"26962026/10/01 07:34:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26972026/10/01 07:34:53 INFO Signed narinfos id=1 count=126982026/10/01 07:34:53 INFO Uploading 1 narinfos26992026/10/01 07:34:53 INFO Received complete push request method=POST path=/api/pushes/1/complete27002026/10/01 07:34:53 WARN Failed to register uploaded object key=axbmhzn6z302xs1dzrsh8plkc0hn2l5h.narinfo error="server returned 404: 404 page not found\n"27012026/10/01 07:34:53 INFO Upload complete. (144ms)2702=== NAME TestClientWithDependencies2703 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-37277-823233434/TestClientWithDependencies3572692299/001/store) requires matching store prefix2704--- PASS: TestClientWithDependencies (3.86s)27052026/10/01 07:34:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.536635166s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27062026/10/01 07:34:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2707--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)2708 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2709 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2710 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.18s)27112026/10/01 07:34:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27122026/10/01 07:34:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02713=== NAME TestPinProtectsFromGC2714 client_integration_test.go:794: Pin successfully protected closure from garbage collection2715--- PASS: TestPinProtectsFromGC (5.59s)27162026/10/01 07:34:55 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27172026/10/01 07:34:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.526434ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27182026/10/01 07:34:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.896786ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27192026/10/01 07:34:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=847.662503ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2720=== NAME TestOrphanedObjectsGCStressTest2721 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains27222026/10/01 07:34:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.539687396s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2723 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2724 orphaned_objects_gc_test.go:509: Stress test completed successfully:2725 orphaned_objects_gc_test.go:510: - Active objects preserved: 202726 orphaned_objects_gc_test.go:511: - Objects deleted: 2102727 orphaned_objects_gc_test.go:512: - Total GC'd: 2102728--- PASS: TestOrphanedObjectsGCStressTest (8.58s)27292026/10/01 07:34:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"27302026/10/01 07:34:58 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27312026/10/01 07:34:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.724369ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27322026/10/01 07:34:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.512142ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27332026/10/01 07:34:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=763.230123ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27342026/10/01 07:35:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.660408118s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27352026/10/01 07:35:01 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27362026/10/01 07:35:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.246889ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27372026/10/01 07:35:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.167061ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27382026/10/01 07:35:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=726.465509ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27392026/10/01 07:35:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.622885771s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2740--- PASS: TestClientErrorHandling (0.00s)2741 --- PASS: TestClientErrorHandling/InvalidStorePath (2.49s)2742 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.75s)2743 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.74s)2744PASS2745{"timestamp":"2026-10-01T07:35:04.763346Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55447","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}27462026-10-01 07:35:05.202 UTC [38118] LOG: received smart shutdown request27472026-10-01 07:35:05.203 UTC [38118] LOG: background worker "logical replication launcher" (PID 38129) exited with exit code 127482026-10-01 07:35:05.222 UTC [38124] LOG: shutting down27492026-10-01 07:35:05.222 UTC [38124] LOG: checkpoint starting: shutdown immediate27502026-10-01 07:35:08.350 UTC [38124] LOG: checkpoint complete: wrote 12717 buffers (77.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 20 recycled; write=0.773 s, sync=2.320 s, total=3.129 s; sync files=23916, longest=0.185 s, average=0.001 s; distance=330990 kB, estimate=330990 kB; lsn=0/15AC8838, redo lsn=0/15AC883827512026-10-01 07:35:08.358 UTC [38118] LOG: database system is shut down2752Running OIDC tests...2753=== RUN TestAudienceForIssuer2754=== PAUSE TestAudienceForIssuer2755=== RUN TestGlobMatch2756=== PAUSE TestGlobMatch2757=== RUN TestValidateToken_ValidToken2758=== PAUSE TestValidateToken_ValidToken2759=== RUN TestValidateToken_WrongAudience2760=== PAUSE TestValidateToken_WrongAudience2761=== RUN TestValidateToken_Expired2762=== PAUSE TestValidateToken_Expired2763=== RUN TestValidateToken_BoundClaimsMismatch2764=== PAUSE TestValidateToken_BoundClaimsMismatch2765=== RUN TestValidateToken_BoundSubjectMismatch2766=== PAUSE TestValidateToken_BoundSubjectMismatch2767=== RUN TestValidateToken_MultipleProviders2768=== PAUSE TestValidateToken_MultipleProviders2769=== RUN TestValidateToken_NoMatchingProvider2770=== PAUSE TestValidateToken_NoMatchingProvider2771=== RUN TestValidateToken_KubernetesServiceAccount2772=== PAUSE TestValidateToken_KubernetesServiceAccount2773=== RUN TestNewValidator_KubernetesRequiresCA2774=== PAUSE TestNewValidator_KubernetesRequiresCA2775=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2776=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2777=== RUN TestPins_ReservedForMatchingRule2778=== PAUSE TestPins_ReservedForMatchingRule2779=== RUN TestPins_TopLevelShorthand2780=== PAUSE TestPins_TopLevelShorthand2781=== RUN TestPins_ConfigValidation2782=== PAUSE TestPins_ConfigValidation2783=== RUN TestScopes_LegacyProviderDefaultsToWrite2784=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2785=== RUN TestScopes_Rules2786=== PAUSE TestScopes_Rules2787=== RUN TestScopes_ConfigValidation2788=== PAUSE TestScopes_ConfigValidation2789=== CONT TestAudienceForIssuer2790--- PASS: TestAudienceForIssuer (0.00s)2791=== CONT TestScopes_ConfigValidation2792--- PASS: TestScopes_ConfigValidation (0.00s)2793=== CONT TestValidateToken_NoMatchingProvider2794=== CONT TestValidateToken_KubernetesServiceAccount2795=== CONT TestPins_TopLevelShorthand2796=== CONT TestValidateToken_Expired2797=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2798=== CONT TestValidateToken_ValidToken2799=== CONT TestNewValidator_KubernetesRequiresCA2800=== CONT TestGlobMatch2801=== RUN TestGlobMatch/foo_foo2802=== PAUSE TestGlobMatch/foo_foo2803=== RUN TestGlobMatch/foo_bar2804=== PAUSE TestGlobMatch/foo_bar2805=== RUN TestGlobMatch/*_2806=== PAUSE TestGlobMatch/*_2807=== RUN TestGlobMatch/*_anything2808=== PAUSE TestGlobMatch/*_anything2809=== RUN TestGlobMatch/foo*_foo2810=== PAUSE TestGlobMatch/foo*_foo2811=== RUN TestGlobMatch/foo*_foobar2812=== PAUSE TestGlobMatch/foo*_foobar2813=== RUN TestGlobMatch/foo*_bar2814=== PAUSE TestGlobMatch/foo*_bar2815=== RUN TestGlobMatch/*bar_bar2816=== PAUSE TestGlobMatch/*bar_bar2817=== RUN TestGlobMatch/*bar_foobar2818=== PAUSE TestGlobMatch/*bar_foobar2819=== RUN TestGlobMatch/*bar_foo2820=== PAUSE TestGlobMatch/*bar_foo2821=== RUN TestGlobMatch/foo*bar_foobar2822=== PAUSE TestGlobMatch/foo*bar_foobar2823=== RUN TestGlobMatch/foo*bar_foo123bar2824=== PAUSE TestGlobMatch/foo*bar_foo123bar2825=== RUN TestGlobMatch/foo*bar_foobarbaz2826=== PAUSE TestGlobMatch/foo*bar_foobarbaz2827=== RUN TestGlobMatch/*/*_foo/bar2828=== PAUSE TestGlobMatch/*/*_foo/bar2829=== RUN TestGlobMatch/*/*_foo2830=== PAUSE TestGlobMatch/*/*_foo2831=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2832=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2833=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02834=== CONT TestPins_ReservedForMatchingRule2835=== CONT TestValidateToken_WrongAudience2836=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02837=== RUN TestGlobMatch/refs/*/main_refs/heads/main2838=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2839=== RUN TestGlobMatch/fo?_foo2840=== PAUSE TestGlobMatch/fo?_foo2841=== RUN TestGlobMatch/fo?_fo2842=== PAUSE TestGlobMatch/fo?_fo2843=== RUN TestGlobMatch/fo?_fooo2844=== PAUSE TestGlobMatch/fo?_fooo2845=== RUN TestGlobMatch/?oo_foo2846=== PAUSE TestGlobMatch/?oo_foo2847=== RUN TestGlobMatch/?oo_boo2848=== PAUSE TestGlobMatch/?oo_boo2849=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2850=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2851=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2852=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2853=== CONT TestScopes_LegacyProviderDefaultsToWrite28542026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55724/oidc2855--- PASS: TestValidateToken_ValidToken (0.02s)2856=== CONT TestScopes_Rules28572026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55726/oidc2858--- PASS: TestScopes_Rules (0.10s)2859=== CONT TestValidateToken_BoundSubjectMismatch28602026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55728/oidc2861--- PASS: TestPins_TopLevelShorthand (0.19s)2862=== CONT TestValidateToken_MultipleProviders28632026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55730/oidc2864--- PASS: TestValidateToken_WrongAudience (0.42s)2865=== CONT TestValidateToken_BoundClaimsMismatch28662026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55732/oidc2867--- PASS: TestValidateToken_Expired (0.44s)2868=== CONT TestPins_ConfigValidation2869--- PASS: TestPins_ConfigValidation (0.00s)2870=== CONT TestGlobMatch/foo_foo2871=== CONT TestGlobMatch/*/*_foo/bar2872=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2873=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2874=== CONT TestGlobMatch/?oo_boo2875=== CONT TestGlobMatch/?oo_foo2876=== CONT TestGlobMatch/fo?_fooo2877=== CONT TestGlobMatch/fo?_fo2878=== CONT TestGlobMatch/fo?_foo2879=== CONT TestGlobMatch/refs/*/main_refs/heads/main2880=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02881=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2882=== CONT TestGlobMatch/*/*_foo2883=== CONT TestGlobMatch/*bar_bar2884=== CONT TestGlobMatch/foo*bar_foobarbaz2885=== CONT TestGlobMatch/foo*bar_foo123bar2886=== CONT TestGlobMatch/foo*bar_foobar2887=== CONT TestGlobMatch/*bar_foo2888=== CONT TestGlobMatch/*bar_foobar2889=== CONT TestGlobMatch/foo*_foo2890=== CONT TestGlobMatch/foo*_bar2891=== CONT TestGlobMatch/foo*_foobar2892=== CONT TestGlobMatch/*_2893=== CONT TestGlobMatch/*_anything2894=== CONT TestGlobMatch/foo_bar2895--- PASS: TestGlobMatch (0.00s)2896 --- PASS: TestGlobMatch/foo_foo (0.00s)2897 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2898 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2899 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2900 --- PASS: TestGlobMatch/?oo_boo (0.00s)2901 --- PASS: TestGlobMatch/?oo_foo (0.00s)2902 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2903 --- PASS: TestGlobMatch/fo?_fo (0.00s)2904 --- PASS: TestGlobMatch/fo?_foo (0.00s)2905 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2906 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2907 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2908 --- PASS: TestGlobMatch/*/*_foo (0.00s)2909 --- PASS: TestGlobMatch/*bar_bar (0.00s)2910 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2911 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2912 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2913 --- PASS: TestGlobMatch/*bar_foo (0.00s)2914 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2915 --- PASS: TestGlobMatch/foo*_foo (0.00s)2916 --- PASS: TestGlobMatch/foo*_bar (0.00s)2917 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2918 --- PASS: TestGlobMatch/*_ (0.00s)2919 --- PASS: TestGlobMatch/*_anything (0.00s)2920 --- PASS: TestGlobMatch/foo_bar (0.00s)29212026/10/01 07:35:10 http: TLS handshake error from 127.0.0.1:55737: remote error: tls: bad certificate2922--- PASS: TestNewValidator_KubernetesRequiresCA (0.46s)29232026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55735/oidc29242026/10/01 07:35:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232925--- PASS: TestValidateToken_BoundClaimsMismatch (0.21s)2926--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.64s)29272026/10/01 07:35:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55743/oidc2928--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.69s)29292026/10/01 07:35:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55733/oidc2930--- PASS: TestValidateToken_NoMatchingProvider (0.78s)29312026/10/01 07:35:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55748/oidc2932--- PASS: TestValidateToken_BoundSubjectMismatch (1.12s)29332026/10/01 07:35:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55747/oidc29342026/10/01 07:35:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:55750/oidc2935--- PASS: TestValidateToken_MultipleProviders (1.19s)29362026/10/01 07:35:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:557532937--- PASS: TestValidateToken_KubernetesServiceAccount (1.50s)29382026/10/01 07:35:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55756/oidc2939--- PASS: TestPins_ReservedForMatchingRule (2.23s)2940PASS2941Running hook tests...2942=== RUN TestSendPathsEmpty2943=== PAUSE TestSendPathsEmpty2944=== RUN TestQueueEnqueueAndFetch2945=== PAUSE TestQueueEnqueueAndFetch2946=== RUN TestQueueDeduplication2947=== PAUSE TestQueueDeduplication2948=== RUN TestQueueRemove2949=== PAUSE TestQueueRemove2950=== RUN TestQueueFetchBatchLimit2951=== PAUSE TestQueueFetchBatchLimit2952=== RUN TestQueueRetryMovesToBack2953=== PAUSE TestQueueRetryMovesToBack2954=== RUN TestQueueFetchRemoveLifecycle2955=== PAUSE TestQueueFetchRemoveLifecycle2956=== RUN TestQueueConcurrentWriters2957=== PAUSE TestQueueConcurrentWriters2958=== RUN TestQueueRemoveLargeClosure2959=== PAUSE TestQueueRemoveLargeClosure2960=== RUN TestServerClientIntegration2961=== PAUSE TestServerClientIntegration2962=== RUN TestServerQueueError2963=== PAUSE TestServerQueueError2964=== RUN TestGetListenerSocketActivation2965 server_test.go:210: === RUN TestGetListenerSocketActivation2966 --- PASS: TestGetListenerSocketActivation (0.00s)2967 PASS2968 2969--- PASS: TestGetListenerSocketActivation (0.01s)2970=== RUN TestDrainIsolatesPoisonPath2971=== PAUSE TestDrainIsolatesPoisonPath2972=== RUN TestRunNotBlockedByPoisonHead2973=== PAUSE TestRunNotBlockedByPoisonHead2974=== RUN TestDrainGivesUpWhenServerDown2975=== PAUSE TestDrainGivesUpWhenServerDown2976=== RUN TestFailedPathPrunedByLaterClosure2977=== PAUSE TestFailedPathPrunedByLaterClosure2978=== RUN TestWorkerUploadsAndRemoves2979=== PAUSE TestWorkerUploadsAndRemoves2980=== RUN TestWorkerSkipsGCdPaths2981=== PAUSE TestWorkerSkipsGCdPaths2982=== RUN TestWorkerPrunesClosureDeps2983=== PAUSE TestWorkerPrunesClosureDeps2984=== RUN TestDrainTimeout2985=== PAUSE TestDrainTimeout2986=== CONT TestSendPathsEmpty2987--- PASS: TestSendPathsEmpty (0.00s)2988=== CONT TestDrainTimeout2989=== CONT TestServerClientIntegration2990=== CONT TestFailedPathPrunedByLaterClosure2991=== CONT TestQueueRemoveLargeClosure2992=== CONT TestQueueConcurrentWriters2993=== CONT TestDrainGivesUpWhenServerDown2994=== CONT TestRunNotBlockedByPoisonHead2995=== CONT TestDrainIsolatesPoisonPath2996=== CONT TestWorkerUploadsAndRemoves2997=== CONT TestServerQueueError29982026/10/01 07:35:12 ERROR Failed to queue paths error="permission denied" count=12999--- PASS: TestServerQueueError (0.00s)3000=== CONT TestQueueRemove3001--- PASS: TestServerClientIntegration (0.00s)3002=== CONT TestQueueFetchRemoveLifecycle30032026/10/01 07:35:12 INFO Uploading batch count=230042026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=230052026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainGivesUpWhenServerDown727396544/002/a30062026/10/01 07:35:12 INFO Uploading batch count=130072026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=130082026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainGivesUpWhenServerDown727396544/002/b30092026/10/01 07:35:12 INFO Uploading batch count=230102026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=230112026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainGivesUpWhenServerDown727396544/002/c30122026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainGivesUpWhenServerDown727396544/002/d30132026/10/01 07:35:12 INFO Uploading batch count=130142026/10/01 07:35:12 INFO Uploading batch count=13015--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)3016=== CONT TestQueueRetryMovesToBack30172026/10/01 07:35:12 INFO Uploading batch count=430182026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=430192026/10/01 07:35:12 INFO Uploading batch count=230202026/10/01 07:35:12 INFO Upload queue status pending=230212026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainIsolatesPoisonPath2718949581/002/bbb30222026/10/01 07:35:12 INFO Uploading batch count=23023--- PASS: TestQueueRemove (0.01s)3024=== CONT TestQueueFetchBatchLimit30252026/10/01 07:35:12 INFO Uploading batch count=230262026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=230272026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainGivesUpWhenServerDown727396544/002/e30282026/10/01 07:35:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-37277-823233434/TestDrainGivesUpWhenServerDown727396544/002/f30292026/10/01 07:35:12 INFO Uploading batch count=130302026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=130312026/10/01 07:35:12 INFO Upload queue status pending=330322026/10/01 07:35:12 INFO Uploading batch count=130332026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=130342026/10/01 07:35:12 ERROR Drain finished with paths left in queue remaining=1030352026/10/01 07:35:12 INFO Uploading batch count=130362026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=130372026/10/01 07:35:12 INFO Uploading batch count=130382026/10/01 07:35:12 ERROR Upload failed error="upload failed" count=130392026/10/01 07:35:12 ERROR Drain finished with paths left in queue remaining=13040--- PASS: TestQueueRetryMovesToBack (0.00s)3041=== CONT TestQueueEnqueueAndFetch3042--- PASS: TestQueueFetchBatchLimit (0.00s)3043=== CONT TestQueueDeduplication3044--- PASS: TestDrainGivesUpWhenServerDown (0.01s)3045=== CONT TestWorkerSkipsGCdPaths3046--- PASS: TestQueueFetchRemoveLifecycle (0.01s)3047=== CONT TestWorkerPrunesClosureDeps3048--- PASS: TestDrainIsolatesPoisonPath (0.01s)3049--- PASS: TestQueueEnqueueAndFetch (0.00s)30502026/10/01 07:35:12 INFO Upload queue status pending=230512026/10/01 07:35:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-37277-823233434/TestWorkerSkipsGCdPaths2009385941/002/nonexistent3052--- PASS: TestQueueDeduplication (0.00s)30532026/10/01 07:35:12 INFO Uploading batch count=130542026/10/01 07:35:12 INFO Upload queue status pending=230552026/10/01 07:35:12 INFO Uploading batch count=13056--- PASS: TestWorkerUploadsAndRemoves (0.03s)3057--- PASS: TestWorkerSkipsGCdPaths (0.03s)3058--- PASS: TestWorkerPrunesClosureDeps (0.03s)3059--- PASS: TestQueueConcurrentWriters (0.07s)30602026/10/01 07:35:12 ERROR Upload failed error="context deadline exceeded" count=230612026/10/01 07:35:12 ERROR Drain finished with paths left in queue remaining=43062--- PASS: TestDrainTimeout (0.21s)3063--- PASS: TestQueueRemoveLargeClosure (0.30s)30642026/10/01 07:35:13 INFO Uploading batch count=130652026/10/01 07:35:13 INFO Uploading batch count=130662026/10/01 07:35:13 INFO Uploading batch count=130672026/10/01 07:35:13 ERROR Upload failed error="upload failed" count=130682026/10/01 07:35:13 INFO Uploading batch count=130692026/10/01 07:35:13 ERROR Upload failed error="upload failed" count=130702026/10/01 07:35:13 INFO Uploading batch count=130712026/10/01 07:35:13 ERROR Upload failed error="upload failed" count=130722026/10/01 07:35:13 INFO Uploading batch count=130732026/10/01 07:35:13 ERROR Upload failed error="upload failed" count=130742026/10/01 07:35:13 ERROR Drain finished with paths left in queue remaining=13075--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3076PASS