niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-darwin.go-unit-tests` · build #235 · 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.06s)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 TestSetClientTLS65=== PAUSE TestSetClientTLS66=== RUN TestSetClientTLSDoesNotMutateDefaultTransport67=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport68=== RUN TestSetClientTLSErrors69=== PAUSE TestSetClientTLSErrors70=== RUN TestStaticToken71=== PAUSE TestStaticToken72=== RUN TestFileTokenReadsAndCaches73=== PAUSE TestFileTokenReadsAndCaches74=== RUN TestFileTokenMissing75=== PAUSE TestFileTokenMissing76=== RUN TestFileTokenEmpty77=== PAUSE TestFileTokenEmpty78=== RUN TestScriptTokenNoExpiryRerunsEveryCall79=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall80=== RUN TestScriptTokenCachesUntilRefresh81=== PAUSE TestScriptTokenCachesUntilRefresh82=== RUN TestScriptTokenEmptyToken83=== PAUSE TestScriptTokenEmptyToken84=== RUN TestScriptTokenBadJSON85=== PAUSE TestScriptTokenBadJSON86=== RUN TestScriptTokenScriptFails87=== PAUSE TestScriptTokenScriptFails88=== RUN TestScriptTokenEmptyCommand89=== PAUSE TestScriptTokenEmptyCommand90=== CONT TestDoServerRequestAttachesToken91=== CONT TestDoWithRetry_BodyReplayedViaGetBody92=== CONT TestPathInfoHashCompatibility93=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)94=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)95=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon96=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon97=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI98=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI99=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512100=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512101=== CONT TestStaticToken102=== CONT TestEncodeNixBase32WithRealHash103=== CONT TestScriptTokenScriptFails104=== CONT TestResolveStorePath105=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1062026/09/21 14:02:41 WARN Rate limiter enabled after throttle name=server-test rate=5107=== CONT TestRateLimiterFeedback108=== RUN TestRateLimiterFeedback/429_enables_limiter109=== PAUSE TestRateLimiterFeedback/429_enables_limiter110=== RUN TestRateLimiterFeedback/503_enables_limiter111=== PAUSE TestRateLimiterFeedback/503_enables_limiter112=== CONT TestPathInfoCACompatibility113=== RUN TestPathInfoCACompatibility/null_ca_field114=== CONT TestParsePathInfoJSONMultiplePaths115=== CONT TestParsePathInfoJSON116--- PASS: TestStaticToken (0.00s)117=== CONT TestScriptTokenEmptyCommand118=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter119=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths120=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths121=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths122--- PASS: TestEncodeNixBase32WithRealHash (0.00s)123=== RUN TestParsePathInfoJSON/Nix_format124=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths125--- PASS: TestScriptTokenEmptyCommand (0.00s)126=== CONT TestScriptTokenBadJSON127=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter128--- PASS: TestResolveStorePath (0.00s)129=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter130=== PAUSE TestParsePathInfoJSON/Nix_format131=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter132=== RUN TestParsePathInfoJSON/Lix_format133=== CONT TestScriptTokenCachesUntilRefresh134=== CONT TestScriptTokenNoExpiryRerunsEveryCall135=== PAUSE TestPathInfoCACompatibility/null_ca_field136=== RUN TestPathInfoCACompatibility/old_string_format_-_text137=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text138=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive139=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140=== CONT TestScriptTokenEmptyToken141=== RUN TestPathInfoCACompatibility/new_structured_format_-_text142=== PAUSE TestParsePathInfoJSON/Lix_format143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text144=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== RUN TestParsePathInfoJSON/empty_input146=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method147=== PAUSE TestParsePathInfoJSON/empty_input148=== CONT TestFileTokenEmpty149=== RUN TestParsePathInfoJSON/whitespace_only150=== PAUSE TestParsePathInfoJSON/whitespace_only151=== RUN TestParsePathInfoJSON/invalid_JSON152=== PAUSE TestParsePathInfoJSON/invalid_JSON153=== CONT TestFileTokenMissing1542026/09/21 14:02:41 WARN Rate limiter enabled after throttle name=server-test rate=51552026/09/21 14:02:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61087156--- PASS: TestDoServerRequestAttachesToken (0.00s)157=== CONT TestFileTokenReadsAndCaches1582026/09/21 14:02:41 WARN Rate limiter backed off name=server-test rate=51592026/09/21 14:02:41 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61087160--- PASS: TestScriptTokenScriptFails (0.00s)161=== CONT TestGetStorePathHash162=== RUN TestGetStorePathHash/valid_store_path163=== PAUSE TestGetStorePathHash/valid_store_path164=== RUN TestGetStorePathHash/basename_without_hyphen_should_error165=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error166=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error167=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error168=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error169=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error170=== CONT TestUploadMultipart_SupersededByPeer171=== RUN TestUploadMultipart_SupersededByPeer/exists172--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)173=== CONT TestEncodeNixBase32174=== RUN TestEncodeNixBase32/test_string_hash175=== PAUSE TestEncodeNixBase32/test_string_hash176=== PAUSE TestUploadMultipart_SupersededByPeer/exists177=== RUN TestEncodeNixBase32/empty_input178=== RUN TestUploadMultipart_SupersededByPeer/missing179=== PAUSE TestUploadMultipart_SupersededByPeer/missing180=== PAUSE TestEncodeNixBase32/empty_input181=== CONT TestDumpPathWriterError182=== CONT TestDumpPathSingleFile183--- PASS: TestFileTokenReadsAndCaches (0.00s)184--- PASS: TestFileTokenEmpty (0.00s)185=== CONT TestStreamPushGivesUpOnDeadServer186--- PASS: TestFileTokenMissing (0.00s)187=== CONT TestDumpPathMatchesNix188=== CONT TestConvertHashToNix32189=== RUN TestConvertHashToNix32/SRI_format_to_Nix32190=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32191=== RUN TestConvertHashToNix32/already_Nix32_format192=== PAUSE TestConvertHashToNix32/already_Nix32_format193=== RUN TestConvertHashToNix32/invalid_format194=== PAUSE TestConvertHashToNix32/invalid_format1952026/09/21 14:02:41 ERROR Upload failed error="connection refused" count=201962026/09/21 14:02:41 ERROR Server seems unavailable, giving up on batch untried=17197=== CONT TestSetClientTLSErrors198--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)199=== CONT TestSetClientTLSDoesNotMutateDefaultTransport200=== RUN TestSetClientTLSErrors/missing_cert_file201=== PAUSE TestSetClientTLSErrors/missing_cert_file202=== RUN TestSetClientTLSErrors/missing_key_file203=== PAUSE TestSetClientTLSErrors/missing_key_file204=== RUN TestSetClientTLSErrors/missing_ca_file205=== PAUSE TestSetClientTLSErrors/missing_ca_file206=== RUN TestSetClientTLSErrors/invalid_ca_file207=== PAUSE TestSetClientTLSErrors/invalid_ca_file208=== CONT TestSetClientTLS209--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)210=== CONT TestStreamPushRequestLine2112026/09/21 14:02:41 ERROR Upload failed error=boom count=1212=== RUN TestSetClientTLS/rejects_connection_without_client_cert213=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert214=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA215=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA216=== RUN TestSetClientTLS/preserves_debug_logging_transport217=== PAUSE TestSetClientTLS/preserves_debug_logging_transport218=== CONT TestFilterOversizedClosures219=== RUN TestFilterOversizedClosures/no_limit_keeps_everything220=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything221=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped222=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped223=== RUN TestFilterOversizedClosures/all_closures_skipped224=== PAUSE TestFilterOversizedClosures/all_closures_skipped225=== CONT TestPartSizeForNAR226=== RUN TestPartSizeForNAR/zero_stays_at_minimum227=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum228=== RUN TestPartSizeForNAR/small_stays_at_minimum229=== PAUSE TestPartSizeForNAR/small_stays_at_minimum230=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum231=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum232=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts233=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts234=== RUN TestPartSizeForNAR/1_TiB235=== PAUSE TestPartSizeForNAR/1_TiB236=== RUN TestPartSizeForNAR/5_TiB_S3_max_object237=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object238=== RUN TestPartSizeForNAR/capped_at_5_GiB239=== PAUSE TestPartSizeForNAR/capped_at_5_GiB240=== CONT TestUploadMultipart_PartsInParallel241--- PASS: TestScriptTokenBadJSON (0.01s)242=== CONT TestStreamPushReportsEveryPath243--- PASS: TestStreamPushReportsEveryPath (0.00s)244=== CONT TestStreamPushIsolatesFailures2452026/09/21 14:02:41 ERROR Upload failed error="bad path" count=3246--- PASS: TestStreamPushIsolatesFailures (0.00s)247=== CONT TestStreamPushBatchesUnderLoad248--- PASS: TestScriptTokenEmptyToken (0.01s)249=== CONT TestCaseHackSuffix250--- PASS: TestStreamPushRequestLine (0.01s)251=== CONT TestShellSplitErrors252--- PASS: TestShellSplitErrors (0.00s)253=== CONT TestShellSplit254--- PASS: TestShellSplit (0.00s)255=== CONT TestRegisterUploadedObjectReusesConnections256--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)257=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)258=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI260=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon261--- PASS: TestPathInfoHashCompatibility (0.00s)262 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)263 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)264 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)265 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)266=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths267=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths268--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)269 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)271=== CONT TestRateLimiterFeedback/429_enables_limiter2722026/09/21 14:02:41 WARN Rate limiter enabled after throttle name=server-test rate=52732026/09/21 14:02:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:61163274--- PASS: TestDumpPathWriterError (0.04s)275=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2762026/09/21 14:02:41 WARN Rate limiter backed off name=server-test rate=5277=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter278=== CONT TestRateLimiterFeedback/503_enables_limiter279=== CONT TestPathInfoCACompatibility/null_ca_field280=== CONT TestParsePathInfoJSON/Nix_format281=== CONT TestPathInfoCACompatibility/new_structured_format_-_text282=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method283=== CONT TestParsePathInfoJSON/whitespace_only284=== CONT TestParsePathInfoJSON/invalid_JSON285=== CONT TestParsePathInfoJSON/empty_input286=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive287=== CONT TestPathInfoCACompatibility/old_string_format_-_text288--- PASS: TestPathInfoCACompatibility (0.00s)289 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)290 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)291 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)292 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)293 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)294=== CONT TestParsePathInfoJSON/Lix_format295--- PASS: TestParsePathInfoJSON (0.00s)296 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)297 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)298 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)299 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)300 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)301=== CONT TestGetStorePathHash/valid_store_path302=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error3032026/09/21 14:02:41 WARN Rate limiter enabled after throttle name=server-test rate=53042026/09/21 14:02:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:61169305=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error306=== CONT TestGetStorePathHash/basename_without_hyphen_should_error307--- PASS: TestGetStorePathHash (0.00s)308 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)309 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)312=== CONT TestUploadMultipart_SupersededByPeer/exists313--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)314=== CONT TestEncodeNixBase32/test_string_hash315=== CONT TestEncodeNixBase32/empty_input316--- PASS: TestEncodeNixBase32 (0.00s)317 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)318 --- PASS: TestEncodeNixBase32/empty_input (0.00s)319=== CONT TestUploadMultipart_SupersededByPeer/missing3202026/09/21 14:02:41 WARN Rate limiter backed off name=server-test rate=5321--- PASS: TestRateLimiterFeedback (0.00s)322 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)326=== CONT TestConvertHashToNix32/SRI_format_to_Nix32327=== CONT TestConvertHashToNix32/already_Nix32_format328=== CONT TestSetClientTLSErrors/missing_cert_file329=== CONT TestSetClientTLSErrors/missing_ca_file330=== CONT TestConvertHashToNix32/invalid_format331--- PASS: TestConvertHashToNix32 (0.00s)332 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)333 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)334 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)335=== CONT TestSetClientTLSErrors/invalid_ca_file336--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)337 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)338 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)339=== CONT TestSetClientTLSErrors/missing_key_file340=== CONT TestSetClientTLS/rejects_connection_without_client_cert341=== CONT TestSetClientTLS/preserves_debug_logging_transport342=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA343--- PASS: TestSetClientTLSErrors (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)345 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)346 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)347 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)348--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)349=== CONT TestFilterOversizedClosures/no_limit_keeps_everything350=== CONT TestPartSizeForNAR/zero_stays_at_minimum351=== CONT TestFilterOversizedClosures/all_closures_skipped3522026/09/21 14:02:41 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=50353=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3542026/09/21 14:02:41 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=2000355--- PASS: TestFilterOversizedClosures (0.00s)356 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)357 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)358 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)359=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts360=== CONT TestPartSizeForNAR/capped_at_5_GiB361=== CONT TestPartSizeForNAR/5_TiB_S3_max_object362=== CONT TestPartSizeForNAR/1_TiB363=== CONT TestPartSizeForNAR/small_stays_at_minimum364=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum365--- PASS: TestPartSizeForNAR (0.00s)366 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)372 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)3732026/09/21 14:02:41 http: TLS handshake error from 127.0.0.1:61175: remote error: tls: bad certificate374--- PASS: TestSetClientTLS (0.00s)375 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)376 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)377 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)378--- PASS: TestDumpPathSingleFile (0.05s)379--- PASS: TestCaseHackSuffix (0.04s)380--- PASS: TestDumpPathMatchesNix (0.06s)381--- PASS: TestStreamPushBatchesUnderLoad (0.10s)382--- PASS: TestUploadMultipart_PartsInParallel (0.61s)383--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)384PASS385Running server tests...386The files belonging to this database system will be owned by user "_nixbld1".387This user must also own the server process.388389The database cluster will be initialized with locale "C".390The default database encoding has accordingly been set to "SQL_ASCII".391The default text search configuration will be set to "english".392393Data page checksums are enabled.394395creating directory /nix/var/nix/builds/nix-62621-2691108556/postgres2891312388/data ... ok396creating subdirectories ... ok397selecting dynamic shared memory implementation ... posix398selecting default "max_connections" ... 100399selecting default "shared_buffers" ... 128MB400selecting default time zone ... UTC401creating configuration files ... ok402running bootstrap script ... ok403performing post-bootstrap initialization ... ok404syncing data to disk ... ok405406initdb: warning: enabling "trust" authentication for local connections407initdb: 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.408409Success. You can now start the database server using:410411 pg_ctl -D /nix/var/nix/builds/nix-62621-2691108556/postgres2891312388/data -l logfile start412413/nix/var/nix/builds/nix-62621-2691108556/postgres2891312388:5432 - no response4142026-09-21 14:02:43.141 UTC [62665] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4152026-09-21 14:02:43.141 UTC [62665] LOG: listening on Unix socket "/nix/var/nix/builds/nix-62621-2691108556/postgres2891312388/.s.PGSQL.5432"4162026-09-21 14:02:43.143 UTC [62672] LOG: database system was shut down at 2026-09-21 14:02:43 UTC4172026-09-21 14:02:43.144 UTC [62665] LOG: database system is ready to accept connections418/nix/var/nix/builds/nix-62621-2691108556/postgres2891312388:5432 - accepting connections419=== RUN TestService_AuthMiddleware420=== PAUSE TestService_AuthMiddleware421=== RUN TestService_AuthMiddleware_MTLSProxyHeader422=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader423=== RUN TestService_AuthMiddleware_MTLSBoundSubjects424=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects425=== RUN TestService_ReadAuthMiddleware426=== PAUSE TestService_ReadAuthMiddleware427=== RUN TestService_AuthMiddleware_OIDC428=== PAUSE TestService_AuthMiddleware_OIDC429=== RUN TestService_RequireScope_OIDC430=== PAUSE TestService_RequireScope_OIDC431=== RUN TestService_ReadScope_PublicByDefault432=== PAUSE TestService_ReadScope_PublicByDefault433=== RUN TestCacheConfigHandler434=== PAUSE TestCacheConfigHandler435=== RUN TestCacheStatsHandler436=== PAUSE TestCacheStatsHandler437=== RUN TestClientCADerivations438=== PAUSE TestClientCADerivations439=== RUN TestClientErrorHandling440=== PAUSE TestClientErrorHandling441=== RUN TestClientIntegration442=== PAUSE TestClientIntegration443=== RUN TestClientMultipleUploads444=== PAUSE TestClientMultipleUploads445=== RUN TestClientWithDependencies446=== PAUSE TestClientWithDependencies447=== RUN TestClientSharedPathCommittedMidPush448=== PAUSE TestClientSharedPathCommittedMidPush449=== RUN TestPinProtectsFromGC450=== PAUSE TestPinProtectsFromGC451=== RUN TestResolveDBConnectionString452=== PAUSE TestResolveDBConnectionString453=== RUN TestLeadElectsOneAndHandsOver454=== PAUSE TestLeadElectsOneAndHandsOver455=== RUN TestLeadIncumbentWinsAfterRestart4562026-09-21 14:02:43.622 UTC [62744] ERROR: relation "goose_db_version" does not exist at character 364572026-09-21 14:02:43.622 UTC [62744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4582026/09/21 14:02:43 OK 20241026095416_initial_model.sql (3.92ms)4592026/09/21 14:02:43 OK 20251210153512_drop_unused_gin_index.sql (557.21µs)4602026/09/21 14:02:43 OK 20251218171726_add_pins.sql (1.02ms)4612026/09/21 14:02:43 OK 20260628120000_add_object_size_and_stats.sql (909.88µs)4622026/09/21 14:02:43 OK 20260905000000_add_claims.sql (1.16ms)4632026/09/21 14:02:43 OK 20260920000000_drop_claims.sql (688.67µs)4642026/09/21 14:02:43 goose: successfully migrated database to version: 202609200000004652026/09/21 14:02:43 OK 1_commit_pending_closure.sql (941.08µs)4662026/09/21 14:02:43 OK 2_object_stats_trigger.sql (231.96µs)4672026/09/21 14:02:43 goose: up to current file version: 24682026/09/21 14:02:43 INFO lead: acquired remote=192.0.2.1:12344692026/09/21 14:02:44 INFO lead: released remote=192.0.2.1:12344702026/09/21 14:02:44 INFO lead: acquired remote=192.0.2.1:12344712026/09/21 14:02:44 INFO lead: released remote=192.0.2.1:1234472--- PASS: TestLeadIncumbentWinsAfterRestart (0.99s)473=== RUN TestLeadEndsOnShutdown474=== PAUSE TestLeadEndsOnShutdown475=== RUN TestGCAdvisoryLockBlocksConcurrentRun4762026-09-21 14:02:44.434 UTC [62748] ERROR: relation "goose_db_version" does not exist at character 364772026-09-21 14:02:44.434 UTC [62748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4782026/09/21 14:02:44 OK 20241026095416_initial_model.sql (3.67ms)4792026/09/21 14:02:44 OK 20251210153512_drop_unused_gin_index.sql (516.71µs)4802026/09/21 14:02:44 OK 20251218171726_add_pins.sql (815.96µs)4812026/09/21 14:02:44 OK 20260628120000_add_object_size_and_stats.sql (930.42µs)4822026/09/21 14:02:44 OK 20260905000000_add_claims.sql (996.92µs)4832026/09/21 14:02:44 OK 20260920000000_drop_claims.sql (613.96µs)4842026/09/21 14:02:44 goose: successfully migrated database to version: 202609200000004852026/09/21 14:02:44 OK 1_commit_pending_closure.sql (831.13µs)4862026/09/21 14:02:44 OK 2_object_stats_trigger.sql (211.54µs)4872026/09/21 14:02:44 goose: up to current file version: 2488--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)489=== RUN TestGCBugBareHashReferences490=== PAUSE TestGCBugBareHashReferences491=== RUN TestGCMetrics492=== PAUSE TestGCMetrics493=== RUN TestGCTaskStore_StartNew494=== PAUSE TestGCTaskStore_StartNew495=== RUN TestGCTaskStore_DeduplicateSameParams496=== PAUSE TestGCTaskStore_DeduplicateSameParams497=== RUN TestGCTaskStore_ConflictDifferentParams498=== PAUSE TestGCTaskStore_ConflictDifferentParams499=== RUN TestGCTaskStore_GetEmpty500=== PAUSE TestGCTaskStore_GetEmpty501=== RUN TestGCTaskStore_GetReturnsLatest502=== PAUSE TestGCTaskStore_GetReturnsLatest503=== RUN TestGCTaskStore_CompletedAllowsNewTask504=== PAUSE TestGCTaskStore_CompletedAllowsNewTask505=== RUN TestGCTaskStore_PhaseUpdates506=== PAUSE TestGCTaskStore_PhaseUpdates507=== RUN TestGCTaskStore_Fail508=== PAUSE TestGCTaskStore_Fail509=== RUN TestGracefulShutdownDrainsInflight510=== PAUSE TestGracefulShutdownDrainsInflight511=== RUN TestService_healthCheckHandler512=== PAUSE TestService_healthCheckHandler513=== RUN TestService_readinessHandler514=== PAUSE TestService_readinessHandler515=== RUN TestGenerateLandingPage516=== PAUSE TestGenerateLandingPage517=== RUN TestCacheConfigHandlerMaxNarSize518=== PAUSE TestCacheConfigHandlerMaxNarSize519=== RUN TestCreatePendingClosureRejectsOversizedNAR520=== PAUSE TestCreatePendingClosureRejectsOversizedNAR521=== RUN TestNARDeduplicationMetadataUploadBug522=== PAUSE TestNARDeduplicationMetadataUploadBug523=== RUN TestMetricsInventory524=== PAUSE TestMetricsInventory525=== RUN TestService_NativeMTLS526=== PAUSE TestService_NativeMTLS527=== RUN TestServerTLSConfig528=== PAUSE TestServerTLSConfig529=== RUN TestMultipartCleanup530=== PAUSE TestMultipartCleanup531=== RUN TestObjectStatsTrigger532=== PAUSE TestObjectStatsTrigger533=== RUN TestOrphanedObjectsGC534=== PAUSE TestOrphanedObjectsGC535=== RUN TestOrphanedObjectsGCStressTest536=== PAUSE TestOrphanedObjectsGCStressTest537=== RUN TestResurrectedObjectNotDeleted538=== PAUSE TestResurrectedObjectNotDeleted539=== RUN TestParseSingleRange540=== PAUSE TestParseSingleRange541=== RUN TestIsValidCachePath542=== PAUSE TestIsValidCachePath543=== RUN TestReadProxyNarinfo544=== PAUSE TestReadProxyNarinfo545=== RUN TestReadProxyNarinfoAlreadyDecompressed546=== PAUSE TestReadProxyNarinfoAlreadyDecompressed547=== RUN TestReadProxyNarStreaming548=== PAUSE TestReadProxyNarStreaming549=== RUN TestReadProxy404550=== PAUSE TestReadProxy404551=== RUN TestReadProxyInvalidPath552=== PAUSE TestReadProxyInvalidPath553=== RUN TestReadProxyHead554=== PAUSE TestReadProxyHead555=== RUN TestReadProxyConditionalGet556=== PAUSE TestReadProxyConditionalGet557=== RUN TestReadProxyRootRedirectsToIndexHTML558=== PAUSE TestReadProxyRootRedirectsToIndexHTML559=== RUN TestReadProxyDisabled560=== PAUSE TestReadProxyDisabled561=== RUN TestReadRedirectNar562=== PAUSE TestReadRedirectNar563=== RUN TestReadRedirectKeepsNarinfoProxied564=== PAUSE TestReadRedirectKeepsNarinfoProxied565=== RUN TestReadProxyRangeRequest566=== PAUSE TestReadProxyRangeRequest567=== RUN TestReadRedirectUsesPublicS3URL568=== PAUSE TestReadRedirectUsesPublicS3URL569=== RUN TestRedundantMultipartUpload570=== PAUSE TestRedundantMultipartUpload571=== RUN TestCompleteMultipartUpload_ErrorButObjectExists572=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists573=== RUN TestCompletedNarNotReofferedAcrossClosures574=== PAUSE TestCompletedNarNotReofferedAcrossClosures575=== RUN TestPresignedUploadRegisteredBeforeCommit576=== PAUSE TestPresignedUploadRegisteredBeforeCommit577=== RUN TestService_Rustfstest578=== PAUSE TestService_Rustfstest579=== RUN TestParseSize580=== PAUSE TestParseSize581=== RUN TestSkippedUploadsHandler582=== PAUSE TestSkippedUploadsHandler583=== RUN TestSystemdListenerNotActivated584--- PASS: TestSystemdListenerNotActivated (0.00s)585=== RUN TestWatchdogBeatsWhenHealthy586--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)587=== RUN TestWatchdogSkipsWhenUnhealthy5882026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5892026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5902026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 14:02:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"597--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)598=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle599=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle600=== RUN TestProxyWriteTimeout601=== PAUSE TestProxyWriteTimeout602=== RUN TestIsValidUploadKey603=== PAUSE TestIsValidUploadKey604=== RUN TestUploadHandlersRejectInvalidKeys605=== PAUSE TestUploadHandlersRejectInvalidKeys606=== RUN TestUploadHandlersRejectOversizedBody607=== PAUSE TestUploadHandlersRejectOversizedBody608=== RUN TestService_cleanupPendingClosuresHandler609=== PAUSE TestService_cleanupPendingClosuresHandler610=== RUN TestService_createPendingClosureHandler611=== PAUSE TestService_createPendingClosureHandler612=== RUN TestService_verifyS3Integrity613=== PAUSE TestService_verifyS3Integrity614=== RUN TestCompleteMultipartUnregistered615=== PAUSE TestCompleteMultipartUnregistered616=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT617=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT618=== CONT TestIsValidCachePath619=== CONT TestService_AuthMiddleware620=== CONT TestGCTaskStore_ConflictDifferentParams621--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)622=== CONT TestCacheConfigHandlerMaxNarSize623=== CONT TestCompleteMultipartUnregistered624=== CONT TestOrphanedObjectsGC625=== CONT TestOrphanedObjectsGCStressTest626=== CONT TestCreatePendingClosureRejectsOversizedNAR627--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)628=== CONT TestCompleteMultipartUpload_ErrorButObjectExists629=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT630=== CONT TestResurrectedObjectNotDeleted631=== RUN TestIsValidCachePath/narinfo632=== CONT TestParseSingleRange633=== PAUSE TestIsValidCachePath/narinfo634=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars635=== RUN TestParseSingleRange/none636=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars637=== PAUSE TestParseSingleRange/none6382026/09/21 14:02:44 INFO Received uploads request method=POST path=/api/pending_closures639=== RUN TestIsValidCachePath/nar_zst640=== PAUSE TestIsValidCachePath/nar_zst641=== RUN TestIsValidCachePath/nar_xz642=== PAUSE TestIsValidCachePath/nar_xz643=== RUN TestIsValidCachePath/nar_bz2644=== PAUSE TestIsValidCachePath/nar_bz2645=== RUN TestParseSingleRange/unknown_unit646=== RUN TestIsValidCachePath/nar_uncompressed647=== PAUSE TestParseSingleRange/unknown_unit648=== PAUSE TestIsValidCachePath/nar_uncompressed649=== RUN TestParseSingleRange/multi-range_ignored650=== PAUSE TestParseSingleRange/multi-range_ignored651=== RUN TestParseSingleRange/malformed_no_dash652=== PAUSE TestParseSingleRange/malformed_no_dash653=== RUN TestIsValidCachePath/ls654=== RUN TestParseSingleRange/malformed_both_empty655=== PAUSE TestIsValidCachePath/ls656=== RUN TestIsValidCachePath/log657--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)658=== PAUSE TestIsValidCachePath/log659=== RUN TestIsValidCachePath/realisation660=== CONT TestService_verifyS3Integrity661=== PAUSE TestIsValidCachePath/realisation662=== RUN TestIsValidCachePath/nix-cache-info663=== PAUSE TestIsValidCachePath/nix-cache-info664=== RUN TestIsValidCachePath/index.html665=== PAUSE TestIsValidCachePath/index.html666=== RUN TestIsValidCachePath/traversal_parent667=== PAUSE TestIsValidCachePath/traversal_parent668=== RUN TestIsValidCachePath/traversal_in_middle669=== PAUSE TestIsValidCachePath/traversal_in_middle670=== RUN TestIsValidCachePath/invalid_char_e671=== PAUSE TestParseSingleRange/malformed_both_empty672=== RUN TestParseSingleRange/malformed_end_before_start673=== PAUSE TestParseSingleRange/malformed_end_before_start674=== RUN TestParseSingleRange/closed675=== PAUSE TestIsValidCachePath/invalid_char_e676=== PAUSE TestParseSingleRange/closed677=== RUN TestIsValidCachePath/invalid_char_u678=== RUN TestParseSingleRange/open-ended679=== PAUSE TestParseSingleRange/open-ended680=== PAUSE TestIsValidCachePath/invalid_char_u681=== RUN TestParseSingleRange/end_clamped_to_size682=== RUN TestIsValidCachePath/random_path683=== PAUSE TestParseSingleRange/end_clamped_to_size684=== RUN TestParseSingleRange/suffix685=== PAUSE TestParseSingleRange/suffix686=== RUN TestParseSingleRange/suffix_exceeds_size687=== PAUSE TestParseSingleRange/suffix_exceeds_size688=== RUN TestParseSingleRange/single_byte689=== PAUSE TestParseSingleRange/single_byte690=== PAUSE TestIsValidCachePath/random_path691=== RUN TestParseSingleRange/start_past_EOF692=== RUN TestIsValidCachePath/empty693=== PAUSE TestParseSingleRange/start_past_EOF694=== PAUSE TestIsValidCachePath/empty695=== RUN TestParseSingleRange/start_far_past_EOF696=== RUN TestIsValidCachePath/leading_slash697=== PAUSE TestParseSingleRange/start_far_past_EOF698=== PAUSE TestIsValidCachePath/leading_slash699=== RUN TestIsValidCachePath/wrong_extension700=== PAUSE TestIsValidCachePath/wrong_extension701=== RUN TestIsValidCachePath/short_hash702=== PAUSE TestIsValidCachePath/short_hash703=== CONT TestService_createPendingClosureHandler704=== CONT TestService_cleanupPendingClosuresHandler7052026-09-21 14:02:45.063 UTC [62770] ERROR: relation "goose_db_version" does not exist at character 367062026-09-21 14:02:45.063 UTC [62770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026-09-21 14:02:45.063 UTC [62774] ERROR: relation "goose_db_version" does not exist at character 367082026-09-21 14:02:45.063 UTC [62774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026-09-21 14:02:45.064 UTC [62771] ERROR: relation "goose_db_version" does not exist at character 367102026-09-21 14:02:45.064 UTC [62771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7112026-09-21 14:02:45.064 UTC [62773] ERROR: relation "goose_db_version" does not exist at character 367122026-09-21 14:02:45.064 UTC [62773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-21 14:02:45.065 UTC [62772] ERROR: relation "goose_db_version" does not exist at character 367142026-09-21 14:02:45.065 UTC [62772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-09-21 14:02:45.066 UTC [62775] ERROR: relation "goose_db_version" does not exist at character 367162026-09-21 14:02:45.066 UTC [62775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026-09-21 14:02:45.067 UTC [62776] ERROR: relation "goose_db_version" does not exist at character 367182026-09-21 14:02:45.067 UTC [62776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026-09-21 14:02:45.067 UTC [62777] ERROR: relation "goose_db_version" does not exist at character 367202026-09-21 14:02:45.067 UTC [62777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7212026-09-21 14:02:45.069 UTC [62778] ERROR: relation "goose_db_version" does not exist at character 367222026-09-21 14:02:45.069 UTC [62778] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026-09-21 14:02:45.069 UTC [62779] ERROR: relation "goose_db_version" does not exist at character 367242026-09-21 14:02:45.069 UTC [62779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026/09/21 14:02:45 OK 20241026095416_initial_model.sql (5.76ms)7262026/09/21 14:02:45 OK 20241026095416_initial_model.sql (7.94ms)7272026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (992.67µs)7282026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (889.46µs)7292026/09/21 14:02:45 OK 20241026095416_initial_model.sql (7.56ms)7302026/09/21 14:02:45 OK 20241026095416_initial_model.sql (7.34ms)7312026/09/21 14:02:45 OK 20241026095416_initial_model.sql (8.94ms)7322026/09/21 14:02:45 OK 20241026095416_initial_model.sql (6.79ms)7332026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)7342026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)7352026/09/21 14:02:45 OK 20251218171726_add_pins.sql (1.98ms)7362026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (768.04µs)7372026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (833.83µs)7382026/09/21 14:02:45 OK 20251218171726_add_pins.sql (2.39ms)7392026/09/21 14:02:45 OK 20241026095416_initial_model.sql (6.07ms)7402026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)7412026/09/21 14:02:45 OK 20251218171726_add_pins.sql (1.34ms)7422026/09/21 14:02:45 OK 20251218171726_add_pins.sql (2.36ms)7432026/09/21 14:02:45 OK 20251218171726_add_pins.sql (2.13ms)7442026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (939.33µs)7452026/09/21 14:02:45 OK 20251218171726_add_pins.sql (2.08ms)7462026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)7472026/09/21 14:02:45 OK 20241026095416_initial_model.sql (9.98ms)7482026/09/21 14:02:45 OK 20260905000000_add_claims.sql (1.45ms)7492026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (795.54µs)7502026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (2.19ms)7512026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)7522026/09/21 14:02:45 OK 20241026095416_initial_model.sql (10.82ms)7532026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (1.91ms)7542026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (1.32ms)7552026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000007562026/09/21 14:02:45 OK 20251218171726_add_pins.sql (1.86ms)7572026/09/21 14:02:45 OK 20260905000000_add_claims.sql (1.75ms)7582026/09/21 14:02:45 OK 20241026095416_initial_model.sql (6.81ms)7592026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (2.1ms)7602026/09/21 14:02:45 OK 20251218171726_add_pins.sql (1.38ms)7612026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (812.08µs)7622026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (538.83µs)7632026/09/21 14:02:45 OK 20260905000000_add_claims.sql (1.98ms)7642026/09/21 14:02:45 OK 20260905000000_add_claims.sql (1.58ms)7652026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (1.62ms)7662026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000007672026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (1.88ms)7682026/09/21 14:02:45 OK 1_commit_pending_closure.sql (1.93ms)7692026/09/21 14:02:45 OK 2_object_stats_trigger.sql (355.96µs)7702026/09/21 14:02:45 goose: up to current file version: 27712026/09/21 14:02:45 OK 20251218171726_add_pins.sql (1.73ms)7722026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (1.77ms)7732026/09/21 14:02:45 OK 20251218171726_add_pins.sql (1.68ms)7742026/09/21 14:02:45 OK 20260905000000_add_claims.sql (2.93ms)7752026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (1.27ms)7762026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000007772026/09/21 14:02:45 OK 20260905000000_add_claims.sql (2.42ms)7782026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (1.28ms)7792026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000007802026/09/21 14:02:45 OK 1_commit_pending_closure.sql (1.36ms)7812026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (910.96µs)7822026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000007832026/09/21 14:02:45 OK 2_object_stats_trigger.sql (648.33µs)7842026/09/21 14:02:45 goose: up to current file version: 27852026/09/21 14:02:45 OK 1_commit_pending_closure.sql (1.2ms)7862026/09/21 14:02:45 OK 1_commit_pending_closure.sql (1.12ms)7872026/09/21 14:02:45 OK 20260905000000_add_claims.sql (2.09ms)7882026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (1.57ms)7892026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (1.19ms)7902026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000007912026/09/21 14:02:45 OK 2_object_stats_trigger.sql (338µs)7922026/09/21 14:02:45 goose: up to current file version: 27932026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (2.02ms)7942026/09/21 14:02:45 OK 1_commit_pending_closure.sql (878.75µs)7952026/09/21 14:02:45 OK 2_object_stats_trigger.sql (561.96µs)7962026/09/21 14:02:45 goose: up to current file version: 27972026/09/21 14:02:45 OK 20260905000000_add_claims.sql (2.19ms)7982026/09/21 14:02:45 OK 2_object_stats_trigger.sql (268.5µs)7992026/09/21 14:02:45 goose: up to current file version: 28002026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (944.33µs)8012026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000008022026/09/21 14:02:45 OK 20260905000000_add_claims.sql (1.33ms)8032026/09/21 14:02:45 OK 1_commit_pending_closure.sql (1.22ms)8042026/09/21 14:02:45 OK 2_object_stats_trigger.sql (197.75µs)8052026/09/21 14:02:45 goose: up to current file version: 28062026/09/21 14:02:45 OK 1_commit_pending_closure.sql (824.63µs)8072026/09/21 14:02:45 OK 2_object_stats_trigger.sql (188.63µs)8082026/09/21 14:02:45 goose: up to current file version: 28092026/09/21 14:02:45 OK 20260905000000_add_claims.sql (12.31ms)8102026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (12.16ms)8112026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000008122026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (11.77ms)8132026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000008142026/09/21 14:02:45 OK 20260920000000_drop_claims.sql (645.75µs)8152026/09/21 14:02:45 goose: successfully migrated database to version: 202609200000008162026/09/21 14:02:45 OK 1_commit_pending_closure.sql (735.21µs)8172026/09/21 14:02:45 OK 2_object_stats_trigger.sql (194.38µs)8182026/09/21 14:02:45 goose: up to current file version: 28192026/09/21 14:02:45 OK 1_commit_pending_closure.sql (631.25µs)8202026/09/21 14:02:45 OK 2_object_stats_trigger.sql (166.29µs)8212026/09/21 14:02:45 goose: up to current file version: 28222026/09/21 14:02:45 OK 1_commit_pending_closure.sql (653.33µs)8232026/09/21 14:02:45 OK 2_object_stats_trigger.sql (183.25µs)8242026/09/21 14:02:45 goose: up to current file version: 28252026/09/21 14:02:45 INFO Received uploads request method=POST path=/api/pending_closures826--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.46s)827=== CONT TestUploadHandlersRejectOversizedBody828=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts829=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts830=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure831=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure832=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart833=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart834=== CONT TestUploadHandlersRejectInvalidKeys835=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info836=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info837=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal838=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal839=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key840=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key841=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key842=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key843=== CONT TestIsValidUploadKey844=== RUN TestIsValidUploadKey/narinfo845=== PAUSE TestIsValidUploadKey/narinfo846=== RUN TestIsValidUploadKey/nar_zst847=== PAUSE TestIsValidUploadKey/nar_zst848=== RUN TestIsValidUploadKey/nar_xz849=== PAUSE TestIsValidUploadKey/nar_xz850=== RUN TestIsValidUploadKey/nar_plain851=== PAUSE TestIsValidUploadKey/nar_plain852=== RUN TestIsValidUploadKey/listing853=== PAUSE TestIsValidUploadKey/listing854=== RUN TestIsValidUploadKey/build_log855=== PAUSE TestIsValidUploadKey/build_log856=== RUN TestIsValidUploadKey/build_log_home-manager_file857=== PAUSE TestIsValidUploadKey/build_log_home-manager_file858=== RUN TestIsValidUploadKey/build_log_plus_in_name859=== PAUSE TestIsValidUploadKey/build_log_plus_in_name860=== RUN TestIsValidUploadKey/build_log_question_mark861=== PAUSE TestIsValidUploadKey/build_log_question_mark862=== RUN TestIsValidUploadKey/build_log_equals863=== PAUSE TestIsValidUploadKey/build_log_equals864=== RUN TestIsValidUploadKey/realisation865=== PAUSE TestIsValidUploadKey/realisation866=== RUN TestIsValidUploadKey/realisation_plus_in_output867=== PAUSE TestIsValidUploadKey/realisation_plus_in_output868=== RUN TestIsValidUploadKey/nix-cache-info869=== PAUSE TestIsValidUploadKey/nix-cache-info870=== RUN TestIsValidUploadKey/index.html871=== PAUSE TestIsValidUploadKey/index.html872=== RUN TestIsValidUploadKey/narinfo_key,_nar_type873=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type874=== RUN TestIsValidUploadKey/nar_key,_narinfo_type875=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type876=== RUN TestIsValidUploadKey/listing_key,_narinfo_type877=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type878=== RUN TestIsValidUploadKey/traversal879=== PAUSE TestIsValidUploadKey/traversal880=== RUN TestIsValidUploadKey/traversal_nar881=== PAUSE TestIsValidUploadKey/traversal_nar882=== RUN TestIsValidUploadKey/absolute883=== PAUSE TestIsValidUploadKey/absolute884=== RUN TestIsValidUploadKey/empty_key885=== PAUSE TestIsValidUploadKey/empty_key886=== RUN TestIsValidUploadKey/unknown_type887=== PAUSE TestIsValidUploadKey/unknown_type888=== CONT TestProxyWriteTimeout889=== RUN TestProxyWriteTimeout/narinfo890=== PAUSE TestProxyWriteTimeout/narinfo891=== RUN TestProxyWriteTimeout/1_GiB_nar892=== PAUSE TestProxyWriteTimeout/1_GiB_nar893=== RUN TestProxyWriteTimeout/10_GiB_nar894=== PAUSE TestProxyWriteTimeout/10_GiB_nar895=== RUN TestProxyWriteTimeout/unknown_size896=== PAUSE TestProxyWriteTimeout/unknown_size897=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8982026/09/21 14:02:45 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"899--- PASS: TestService_AuthMiddleware (0.57s)900=== CONT TestSkippedUploadsHandler9012026/09/21 14:02:45 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000902--- PASS: TestSkippedUploadsHandler (0.00s)903=== CONT TestParseSize904--- PASS: TestParseSize (0.00s)905=== CONT TestService_Rustfstest906--- PASS: TestResurrectedObjectNotDeleted (0.81s)907=== CONT TestPresignedUploadRegisteredBeforeCommit9082026/09/21 14:02:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9092026/09/21 14:02:45 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst910--- PASS: TestCompleteMultipartUnregistered (0.87s)911=== CONT TestCompletedNarNotReofferedAcrossClosures9122026/09/21 14:02:45 INFO Received uploads request method=POST path=/api/pending_closures9132026-09-21 14:02:45.889 UTC [62799] ERROR: relation "goose_db_version" does not exist at character 369142026-09-21 14:02:45.889 UTC [62799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/09/21 14:02:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9162026/09/21 14:02:45 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzJmMTAwY2MtNDE3MC00ZTlkLWE4NmQtMzdiOThhNTJlZmY2LjMyYTdkNjA1LWQ3ZjItNDFhYi04OTZiLWZkYmJjNDczOTNiYXgxNzg5OTk5MzY1NzM5NzU5MDAw9172026/09/21 14:02:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzJmMTAwY2MtNDE3MC00ZTlkLWE4NmQtMzdiOThhNTJlZmY2LjMyYTdkNjA1LWQ3ZjItNDFhYi04OTZiLWZkYmJjNDczOTNiYXgxNzg5OTk5MzY1NzM5NzU5MDAw parts=1918--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.19s)919=== CONT TestClientMultipleUploads9202026-09-21 14:02:45.971 UTC [62802] ERROR: relation "goose_db_version" does not exist at character 369212026-09-21 14:02:45.971 UTC [62802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026/09/21 14:02:45 OK 20241026095416_initial_model.sql (48.28ms)9232026/09/21 14:02:45 OK 20251210153512_drop_unused_gin_index.sql (7.71ms)9242026/09/21 14:02:45 OK 20251218171726_add_pins.sql (6.86ms)9252026/09/21 14:02:45 OK 20260628120000_add_object_size_and_stats.sql (4ms)9262026/09/21 14:02:46 OK 20260905000000_add_claims.sql (16.62ms)9272026/09/21 14:02:46 OK 20260920000000_drop_claims.sql (5.89ms)9282026/09/21 14:02:46 goose: successfully migrated database to version: 202609200000009292026/09/21 14:02:46 OK 1_commit_pending_closure.sql (14.89ms)9302026/09/21 14:02:46 OK 20241026095416_initial_model.sql (41.51ms)9312026/09/21 14:02:46 OK 2_object_stats_trigger.sql (493.75µs)9322026/09/21 14:02:46 goose: up to current file version: 29332026/09/21 14:02:46 OK 20251210153512_drop_unused_gin_index.sql (13.9ms)9342026-09-21 14:02:46.050 UTC [62805] ERROR: relation "goose_db_version" does not exist at character 369352026-09-21 14:02:46.050 UTC [62805] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9362026/09/21 14:02:46 OK 20251218171726_add_pins.sql (6.85ms)9372026/09/21 14:02:46 OK 20260628120000_add_object_size_and_stats.sql (11.08ms)9382026/09/21 14:02:46 OK 20260905000000_add_claims.sql (15.19ms)9392026/09/21 14:02:46 OK 20260920000000_drop_claims.sql (10.21ms)9402026/09/21 14:02:46 goose: successfully migrated database to version: 202609200000009412026/09/21 14:02:46 OK 1_commit_pending_closure.sql (836.04µs)9422026/09/21 14:02:46 OK 2_object_stats_trigger.sql (231.25µs)9432026/09/21 14:02:46 goose: up to current file version: 29442026/09/21 14:02:46 OK 20241026095416_initial_model.sql (36.76ms)9452026/09/21 14:02:46 INFO Received uploads request method=POST path=/api/pending_closures9462026/09/21 14:02:46 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/21 14:02:46 INFO Received uploads request method=POST path=/api/pending_closures9482026/09/21 14:02:46 OK 20251210153512_drop_unused_gin_index.sql (7.6ms)9492026/09/21 14:02:46 OK 20251218171726_add_pins.sql (986.75µs)9502026/09/21 14:02:46 OK 20260628120000_add_object_size_and_stats.sql (8.61ms)9512026/09/21 14:02:46 OK 20260905000000_add_claims.sql (17.3ms)9522026/09/21 14:02:46 OK 20260920000000_drop_claims.sql (12.68ms)9532026/09/21 14:02:46 goose: successfully migrated database to version: 202609200000009542026-09-21 14:02:46.155 UTC [62815] ERROR: relation "goose_db_version" does not exist at character 369552026-09-21 14:02:46.155 UTC [62815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9562026/09/21 14:02:46 OK 1_commit_pending_closure.sql (1.2ms)9572026/09/21 14:02:46 OK 2_object_stats_trigger.sql (398.25µs)9582026/09/21 14:02:46 goose: up to current file version: 29592026/09/21 14:02:46 OK 20241026095416_initial_model.sql (81.05ms)9602026/09/21 14:02:46 OK 20251210153512_drop_unused_gin_index.sql (14.68ms)9612026/09/21 14:02:46 OK 20251218171726_add_pins.sql (26.86ms)9622026/09/21 14:02:46 OK 20260628120000_add_object_size_and_stats.sql (25.71ms)9632026/09/21 14:02:46 OK 20260905000000_add_claims.sql (6.08ms)9642026/09/21 14:02:46 OK 20260920000000_drop_claims.sql (9.24ms)9652026/09/21 14:02:46 goose: successfully migrated database to version: 202609200000009662026/09/21 14:02:46 OK 1_commit_pending_closure.sql (1.55ms)9672026/09/21 14:02:46 OK 2_object_stats_trigger.sql (347.5µs)9682026/09/21 14:02:46 goose: up to current file version: 2969=== NAME TestOrphanedObjectsGC970 orphaned_objects_gc_test.go:290: GC Test Summary:971 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A972 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B973 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)974 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)975 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects976--- PASS: TestOrphanedObjectsGC (1.69s)977=== CONT TestGCTaskStore_DeduplicateSameParams978--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)979=== CONT TestGCTaskStore_StartNew980--- PASS: TestGCTaskStore_StartNew (0.00s)981=== CONT TestGCMetrics9822026/09/21 14:02:46 INFO Received cleanup request method=DELETE path=/api/pending_closures9832026/09/21 14:02:46 INFO Aborted multipart uploads count=09842026/09/21 14:02:46 INFO Received uploads request method=POST path=/api/pending_closures9852026/09/21 14:02:46 INFO Received cleanup request method=DELETE path=/api/pending_closures9862026/09/21 14:02:46 INFO Aborted multipart uploads count=19872026/09/21 14:02:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9882026-09-21 14:02:46.558 UTC [62779] ERROR: Closure does not exist: id=19892026-09-21 14:02:46.558 UTC [62779] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9902026-09-21 14:02:46.558 UTC [62779] STATEMENT: -- name: CommitPendingClosure :exec991 SELECT commit_pending_closure($1::bigint)992 993--- PASS: TestService_cleanupPendingClosuresHandler (1.82s)994=== CONT TestGCBugBareHashReferences9952026/09/21 14:02:46 INFO Received uploads request method=POST path=/api/pending_closures9962026/09/21 14:02:46 INFO Received uploads request method=POST path=/api/pending_closures9972026-09-21 14:02:46.977 UTC [62829] ERROR: relation "goose_db_version" does not exist at character 369982026-09-21 14:02:46.977 UTC [62829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC999--- PASS: TestService_Rustfstest (1.88s)1000=== CONT TestLeadEndsOnShutdown10012026/09/21 14:02:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10022026/09/21 14:02:47 OK 20241026095416_initial_model.sql (189.72ms)10032026/09/21 14:02:47 OK 20251210153512_drop_unused_gin_index.sql (11.49ms)10042026/09/21 14:02:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10052026/09/21 14:02:47 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzJmMTAwY2MtNDE3MC00ZTlkLWE4NmQtMzdiOThhNTJlZmY2LjljNDU0ZGU0LWJiZmQtNGI3Yy1iZjdiLTRiZDIwNTFmZWRhM3gxNzg5OTk5MzY2MTE3NTk4MDAw parts=1010062026/09/21 14:02:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10072026/09/21 14:02:47 OK 20251218171726_add_pins.sql (5.43ms)10082026/09/21 14:02:47 INFO Completed upload id=110092026/09/21 14:02:47 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010102026/09/21 14:02:47 INFO Received uploads request method=POST path=/api/pending_closures10112026/09/21 14:02:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures10122026/09/21 14:02:47 INFO Aborted multipart uploads count=010132026/09/21 14:02:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=010142026/09/21 14:02:47 OK 20260628120000_add_object_size_and_stats.sql (16.42ms)10152026/09/21 14:02:47 INFO Vacuumed table table=pending_closures10162026/09/21 14:02:47 OK 20260905000000_add_claims.sql (51.29ms)10172026/09/21 14:02:47 INFO Vacuumed table table=pending_objects10182026/09/21 14:02:47 INFO Vacuumed table table=multipart_uploads10192026/09/21 14:02:47 OK 20260920000000_drop_claims.sql (21.32ms)10202026/09/21 14:02:47 goose: successfully migrated database to version: 2026092000000010212026/09/21 14:02:47 OK 1_commit_pending_closure.sql (1.12ms)10222026/09/21 14:02:47 OK 2_object_stats_trigger.sql (222.33µs)10232026/09/21 14:02:47 goose: up to current file version: 210242026/09/21 14:02:47 INFO Vacuumed table table=closures10252026/09/21 14:02:47 INFO Vacuumed table table=objects10262026/09/21 14:02:47 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001027--- PASS: TestService_createPendingClosureHandler (2.66s)1028=== CONT TestLeadElectsOneAndHandsOver10292026/09/21 14:02:47 INFO Received uploads request method=POST path=/api/pending_closures10302026/09/21 14:02:47 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10312026/09/21 14:02:47 INFO Received uploads request method=POST path=/api/pending_closures1032--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.90s)1033=== CONT TestResolveDBConnectionString1034=== RUN TestResolveDBConnectionString/flag_wins1035=== PAUSE TestResolveDBConnectionString/flag_wins1036=== RUN TestResolveDBConnectionString/file_when_flag_empty1037=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1038=== RUN TestResolveDBConnectionString/missing_file_is_an_error1039=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1040=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1041=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1042=== RUN TestResolveDBConnectionString/nothing_configured1043=== PAUSE TestResolveDBConnectionString/nothing_configured1044=== CONT TestPinProtectsFromGC10452026/09/21 14:02:47 INFO Received uploads request method=POST path=/api/pending_closures10462026/09/21 14:02:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10472026/09/21 14:02:47 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzJmMTAwY2MtNDE3MC00ZTlkLWE4NmQtMzdiOThhNTJlZmY2LjRlOGRiMjQyLWFhZjctNDY0Mi1hMmVlLWJjZWZiNmVlMzdmZXgxNzg5OTk5MzY2NzAwNDExMDAw parts=1010482026/09/21 14:02:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10492026-09-21 14:02:47.918 UTC [62850] ERROR: relation "goose_db_version" does not exist at character 3610502026-09-21 14:02:47.918 UTC [62850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10512026/09/21 14:02:47 INFO Completed upload id=110522026/09/21 14:02:47 INFO Received uploads request method=POST path=/api/pending_closures10532026/09/21 14:02:47 INFO Received uploads request method=POST path=/api/pending_closures10542026/09/21 14:02:47 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10552026/09/21 14:02:47 WARN Found objects in DB but missing from S3, will re-upload count=11056--- PASS: TestService_verifyS3Integrity (3.20s)1057=== CONT TestClientSharedPathCommittedMidPush10582026-09-21 14:02:47.934 UTC [62852] ERROR: relation "goose_db_version" does not exist at character 3610592026-09-21 14:02:47.934 UTC [62852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026/09/21 14:02:47 OK 20241026095416_initial_model.sql (60.53ms)10612026/09/21 14:02:47 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)1062=== NAME TestClientMultipleUploads1063 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-62621-2691108556/TestClientMultipleUploads3897021939/001/store/j49cma97b9vmffvq6dn8yz77immknnjw-test-file-0.txt10642026/09/21 14:02:47 OK 20241026095416_initial_model.sql (59.99ms)10652026/09/21 14:02:48 OK 20251218171726_add_pins.sql (2.71ms)10662026/09/21 14:02:48 OK 20251210153512_drop_unused_gin_index.sql (772.54µs)10672026/09/21 14:02:48 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)10682026/09/21 14:02:48 OK 20251218171726_add_pins.sql (2.3ms)10692026/09/21 14:02:48 OK 20260905000000_add_claims.sql (1.88ms)10702026/09/21 14:02:48 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)10712026/09/21 14:02:48 OK 20260920000000_drop_claims.sql (1ms)10722026/09/21 14:02:48 goose: successfully migrated database to version: 2026092000000010732026/09/21 14:02:48 OK 1_commit_pending_closure.sql (1.52ms)10742026/09/21 14:02:48 OK 20260905000000_add_claims.sql (1.87ms)10752026/09/21 14:02:48 OK 2_object_stats_trigger.sql (546.25µs)10762026/09/21 14:02:48 goose: up to current file version: 210772026/09/21 14:02:48 OK 20260920000000_drop_claims.sql (1.28ms)10782026/09/21 14:02:48 goose: successfully migrated database to version: 2026092000000010792026/09/21 14:02:48 OK 1_commit_pending_closure.sql (798.63µs)10802026/09/21 14:02:48 OK 2_object_stats_trigger.sql (211.67µs)10812026/09/21 14:02:48 goose: up to current file version: 21082 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-62621-2691108556/TestClientMultipleUploads3897021939/001/store/la1yavlc84shc4yqaqzd4nbfxp2cv0bk-test-file-1.txt1083 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-62621-2691108556/TestClientMultipleUploads3897021939/001/store/v5irpkzdqwn4rqsv1566ylbgpdqflrm1-test-file-2.txt10842026/09/21 14:02:48 INFO Aborted multipart uploads count=010852026/09/21 14:02:48 WARN Force mode enabled - objects will be deleted immediately without grace period10862026/09/21 14:02:48 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=010872026/09/21 14:02:48 INFO Vacuumed table table=pending_closures10882026/09/21 14:02:48 INFO Vacuumed table table=pending_objects10892026/09/21 14:02:48 INFO Vacuumed table table=multipart_uploads10902026/09/21 14:02:48 INFO Vacuumed table table=closures10912026/09/21 14:02:48 INFO Vacuumed table table=objects1092--- PASS: TestGCMetrics (1.79s)1093=== CONT TestClientWithDependencies10942026/09/21 14:02:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10952026/09/21 14:02:48 INFO Received uploads request method=POST path=/api/pending_closures10962026/09/21 14:02:48 INFO Received uploads request method=POST path=/api/pending_closures10972026/09/21 14:02:48 INFO Received uploads request method=POST path=/api/pending_closures10982026/09/21 14:02:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10992026/09/21 14:02:48 INFO Uploading la1yavlc84shc4yqaqzd4nbfxp2cv0bk-test-file-1.txt (160B)11002026/09/21 14:02:48 INFO Uploading j49cma97b9vmffvq6dn8yz77immknnjw-test-file-0.txt (160B)11012026/09/21 14:02:48 INFO Uploading v5irpkzdqwn4rqsv1566ylbgpdqflrm1-test-file-2.txt (160B)11022026/09/21 14:02:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11032026/09/21 14:02:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11042026/09/21 14:02:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11052026/09/21 14:02:48 WARN Failed to register uploaded object key=la1yavlc84shc4yqaqzd4nbfxp2cv0bk.ls error="server returned 404: 404 page not found\n"11062026/09/21 14:02:48 WARN Failed to register uploaded object key=v5irpkzdqwn4rqsv1566ylbgpdqflrm1.ls error="server returned 404: 404 page not found\n"11072026/09/21 14:02:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign11082026/09/21 14:02:48 WARN Failed to register uploaded object key=j49cma97b9vmffvq6dn8yz77immknnjw.ls error="server returned 404: 404 page not found\n"11092026/09/21 14:02:48 INFO Signed narinfos id=3 count=111102026/09/21 14:02:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11112026/09/21 14:02:48 INFO Signed narinfos id=1 count=111122026/09/21 14:02:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11132026/09/21 14:02:48 INFO Signed narinfos id=2 count=111142026/09/21 14:02:48 INFO Uploading 3 narinfos11152026/09/21 14:02:48 WARN Failed to register uploaded object key=la1yavlc84shc4yqaqzd4nbfxp2cv0bk.narinfo error="server returned 404: 404 page not found\n"11162026/09/21 14:02:48 WARN Failed to register uploaded object key=j49cma97b9vmffvq6dn8yz77immknnjw.narinfo error="server returned 404: 404 page not found\n"11172026/09/21 14:02:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11182026/09/21 14:02:48 WARN Failed to register uploaded object key=v5irpkzdqwn4rqsv1566ylbgpdqflrm1.narinfo error="server returned 404: 404 page not found\n"11192026/09/21 14:02:48 INFO Completed upload id=211202026/09/21 14:02:48 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11212026/09/21 14:02:48 INFO Completed upload id=311222026/09/21 14:02:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11232026/09/21 14:02:48 INFO Completed upload id=111242026/09/21 14:02:48 INFO Upload complete. (237ms)1125=== NAME TestClientMultipleUploads1126 client_integration_test.go:369: Uploaded 3 paths in 271.424917ms1127--- PASS: TestClientMultipleUploads (2.55s)1128=== CONT TestReadProxyRootRedirectsToIndexHTML11292026-09-21 14:02:48.484 UTC [62871] ERROR: relation "goose_db_version" does not exist at character 3611302026-09-21 14:02:48.484 UTC [62871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11312026-09-21 14:02:48.490 UTC [62873] ERROR: relation "goose_db_version" does not exist at character 3611322026-09-21 14:02:48.490 UTC [62873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026-09-21 14:02:48.492 UTC [62874] ERROR: relation "goose_db_version" does not exist at character 3611342026-09-21 14:02:48.492 UTC [62874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11352026/09/21 14:02:48 OK 20241026095416_initial_model.sql (40.94ms)11362026/09/21 14:02:48 OK 20241026095416_initial_model.sql (24.66ms)11372026/09/21 14:02:48 OK 20241026095416_initial_model.sql (32ms)11382026/09/21 14:02:48 OK 20251210153512_drop_unused_gin_index.sql (596.79µs)11392026/09/21 14:02:48 OK 20251210153512_drop_unused_gin_index.sql (720.25µs)11402026/09/21 14:02:48 OK 20251210153512_drop_unused_gin_index.sql (748.58µs)11412026/09/21 14:02:48 OK 20251218171726_add_pins.sql (1.11ms)11422026/09/21 14:02:48 OK 20251218171726_add_pins.sql (1.16ms)11432026/09/21 14:02:48 OK 20251218171726_add_pins.sql (2.12ms)11442026/09/21 14:02:48 OK 20260628120000_add_object_size_and_stats.sql (26.58ms)11452026/09/21 14:02:48 OK 20260628120000_add_object_size_and_stats.sql (33.49ms)11462026/09/21 14:02:48 OK 20260628120000_add_object_size_and_stats.sql (33.11ms)11472026/09/21 14:02:48 OK 20260905000000_add_claims.sql (13.25ms)11482026/09/21 14:02:48 OK 20260905000000_add_claims.sql (13.21ms)11492026/09/21 14:02:48 OK 20260905000000_add_claims.sql (27.83ms)11502026/09/21 14:02:48 OK 20260920000000_drop_claims.sql (8.11ms)11512026/09/21 14:02:48 goose: successfully migrated database to version: 2026092000000011522026/09/21 14:02:48 OK 20260920000000_drop_claims.sql (8.96ms)11532026/09/21 14:02:48 goose: successfully migrated database to version: 2026092000000011542026/09/21 14:02:48 OK 20260920000000_drop_claims.sql (1.9ms)11552026/09/21 14:02:48 goose: successfully migrated database to version: 2026092000000011562026/09/21 14:02:48 OK 1_commit_pending_closure.sql (1.36ms)11572026/09/21 14:02:48 OK 1_commit_pending_closure.sql (1.58ms)11582026/09/21 14:02:48 OK 2_object_stats_trigger.sql (529.83µs)11592026/09/21 14:02:48 goose: up to current file version: 211602026/09/21 14:02:48 OK 2_object_stats_trigger.sql (594.63µs)11612026/09/21 14:02:48 goose: up to current file version: 211622026/09/21 14:02:48 OK 1_commit_pending_closure.sql (1.41ms)11632026/09/21 14:02:48 OK 2_object_stats_trigger.sql (450.83µs)11642026/09/21 14:02:48 goose: up to current file version: 21165--- PASS: TestGCBugBareHashReferences (2.13s)1166=== CONT TestRedundantMultipartUpload11672026/09/21 14:02:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11682026/09/21 14:02:48 INFO lead: acquired remote=192.0.2.1:123411692026/09/21 14:02:48 INFO lead: released remote=192.0.2.1:12341170--- PASS: TestLeadEndsOnShutdown (1.62s)1171=== CONT TestReadRedirectUsesPublicS3URL11722026/09/21 14:02:48 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzJmMTAwY2MtNDE3MC00ZTlkLWE4NmQtMzdiOThhNTJlZmY2LjRmNTBhNzYxLTJhMGQtNDFkNi1hZDJkLWNhYTE5NzQ2ZDQzMXgxNzg5OTk5MzY3NjMzNDU3MDAw parts=1211732026/09/21 14:02:48 INFO Received uploads request method=POST path=/api/pending_closures1174--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.24s)1175=== CONT TestReadProxyRangeRequest11762026-09-21 14:02:48.957 UTC [62881] ERROR: relation "goose_db_version" does not exist at character 3611772026-09-21 14:02:48.957 UTC [62881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11782026/09/21 14:02:48 INFO lead: acquired remote=192.0.2.1:123411792026/09/21 14:02:49 OK 20241026095416_initial_model.sql (61.63ms)11802026/09/21 14:02:49 OK 20251210153512_drop_unused_gin_index.sql (6.25ms)11812026/09/21 14:02:49 OK 20251218171726_add_pins.sql (7.33ms)11822026/09/21 14:02:49 OK 20260628120000_add_object_size_and_stats.sql (17.8ms)11832026/09/21 14:02:49 OK 20260905000000_add_claims.sql (28.42ms)11842026/09/21 14:02:49 OK 20260920000000_drop_claims.sql (16.71ms)11852026/09/21 14:02:49 goose: successfully migrated database to version: 2026092000000011862026/09/21 14:02:49 OK 1_commit_pending_closure.sql (936.42µs)11872026/09/21 14:02:49 OK 2_object_stats_trigger.sql (246.13µs)11882026/09/21 14:02:49 goose: up to current file version: 211892026/09/21 14:02:49 INFO lead: released remote=192.0.2.1:123411902026-09-21 14:02:49.172 UTC [62883] ERROR: relation "goose_db_version" does not exist at character 3611912026-09-21 14:02:49.172 UTC [62883] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/09/21 14:02:49 INFO lead: acquired remote=192.0.2.1:123411932026/09/21 14:02:49 INFO lead: released remote=192.0.2.1:12341194--- PASS: TestLeadElectsOneAndHandsOver (1.79s)1195=== CONT TestReadRedirectKeepsNarinfoProxied11962026/09/21 14:02:49 OK 20241026095416_initial_model.sql (91.6ms)11972026/09/21 14:02:49 OK 20251210153512_drop_unused_gin_index.sql (6.95ms)11982026/09/21 14:02:49 OK 20251218171726_add_pins.sql (12.64ms)1199=== NAME TestPinProtectsFromGC1200 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-62621-2691108556/TestPinProtectsFromGC954338770/001/store/i8c3gb7y8cp42fx5si8g38c2cdply2ay-pinned-file.txt1201 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-62621-2691108556/TestPinProtectsFromGC954338770/001/store/5j1a61jqv8xpida9fxfilv7kyfmc4wkw-unpinned-file.txt12022026/09/21 14:02:49 OK 20260628120000_add_object_size_and_stats.sql (23.38ms)12032026/09/21 14:02:49 OK 20260905000000_add_claims.sql (13.21ms)12042026/09/21 14:02:49 OK 20260920000000_drop_claims.sql (2ms)12052026/09/21 14:02:49 goose: successfully migrated database to version: 2026092000000012062026-09-21 14:02:49.349 UTC [62893] ERROR: relation "goose_db_version" does not exist at character 3612072026-09-21 14:02:49.349 UTC [62893] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12082026/09/21 14:02:49 OK 1_commit_pending_closure.sql (2.17ms)12092026/09/21 14:02:49 OK 2_object_stats_trigger.sql (429.08µs)12102026/09/21 14:02:49 goose: up to current file version: 212112026/09/21 14:02:49 OK 20241026095416_initial_model.sql (45.84ms)12122026/09/21 14:02:49 OK 20251210153512_drop_unused_gin_index.sql (12.68ms)12132026/09/21 14:02:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12142026/09/21 14:02:49 OK 20251218171726_add_pins.sql (15.31ms)12152026/09/21 14:02:49 OK 20260628120000_add_object_size_and_stats.sql (17.66ms)12162026/09/21 14:02:49 OK 20260905000000_add_claims.sql (27.12ms)12172026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures12182026/09/21 14:02:49 OK 20260920000000_drop_claims.sql (15.22ms)12192026/09/21 14:02:49 goose: successfully migrated database to version: 2026092000000012202026/09/21 14:02:49 OK 1_commit_pending_closure.sql (929.88µs)12212026/09/21 14:02:49 OK 2_object_stats_trigger.sql (286.83µs)12222026/09/21 14:02:49 goose: up to current file version: 212232026/09/21 14:02:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12242026/09/21 14:02:49 INFO Uploading i8c3gb7y8cp42fx5si8g38c2cdply2ay-pinned-file.txt (128B)12252026/09/21 14:02:49 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12262026-09-21 14:02:49.517 UTC [62903] ERROR: relation "goose_db_version" does not exist at character 3612272026-09-21 14:02:49.517 UTC [62903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12282026/09/21 14:02:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12292026/09/21 14:02:49 WARN Failed to register uploaded object key=i8c3gb7y8cp42fx5si8g38c2cdply2ay.ls error="server returned 404: 404 page not found\n"12302026/09/21 14:02:49 INFO Signed narinfos id=1 count=112312026/09/21 14:02:49 INFO Uploading 1 narinfos12322026/09/21 14:02:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12332026/09/21 14:02:49 WARN Failed to register uploaded object key=i8c3gb7y8cp42fx5si8g38c2cdply2ay.narinfo error="server returned 404: 404 page not found\n"12342026/09/21 14:02:49 INFO Completed upload id=112352026/09/21 14:02:49 INFO Upload complete. (169ms)1236=== NAME TestOrphanedObjectsGCStressTest1237 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains12382026/09/21 14:02:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12392026-09-21 14:02:49.612 UTC [62915] ERROR: relation "goose_db_version" does not exist at character 3612402026-09-21 14:02:49.612 UTC [62915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12412026/09/21 14:02:49 OK 20241026095416_initial_model.sql (76.1ms)12422026-09-21 14:02:49.620 UTC [62916] ERROR: relation "goose_db_version" does not exist at character 3612432026-09-21 14:02:49.620 UTC [62916] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026/09/21 14:02:49 OK 20251210153512_drop_unused_gin_index.sql (5.08ms)12452026/09/21 14:02:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12462026/09/21 14:02:49 OK 20251218171726_add_pins.sql (6.64ms)12472026/09/21 14:02:49 OK 20260628120000_add_object_size_and_stats.sql (16.57ms)1248 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion12492026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures12502026/09/21 14:02:49 OK 20260905000000_add_claims.sql (19.63ms)12512026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures12522026/09/21 14:02:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12532026/09/21 14:02:49 INFO Uploading 5j1a61jqv8xpida9fxfilv7kyfmc4wkw-unpinned-file.txt (128B)12542026/09/21 14:02:49 OK 20260920000000_drop_claims.sql (12.26ms)12552026/09/21 14:02:49 goose: successfully migrated database to version: 2026092000000012562026/09/21 14:02:49 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12572026/09/21 14:02:49 OK 1_commit_pending_closure.sql (1.16ms)12582026/09/21 14:02:49 OK 2_object_stats_trigger.sql (267.5µs)12592026/09/21 14:02:49 goose: up to current file version: 212602026/09/21 14:02:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12612026/09/21 14:02:49 INFO Signed narinfos id=2 count=112622026/09/21 14:02:49 INFO Uploading 1 narinfos12632026/09/21 14:02:49 WARN Failed to register uploaded object key=5j1a61jqv8xpida9fxfilv7kyfmc4wkw.ls error="server returned 404: 404 page not found\n"12642026/09/21 14:02:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12652026/09/21 14:02:49 WARN Failed to register uploaded object key=5j1a61jqv8xpida9fxfilv7kyfmc4wkw.narinfo error="server returned 404: 404 page not found\n"12662026/09/21 14:02:49 INFO Completed upload id=212672026/09/21 14:02:49 INFO Upload complete. (118ms)12682026/09/21 14:02:49 OK 20241026095416_initial_model.sql (69.53ms)12692026/09/21 14:02:49 OK 20241026095416_initial_model.sql (62.48ms)12702026/09/21 14:02:49 OK 20251210153512_drop_unused_gin_index.sql (5.45ms)12712026/09/21 14:02:49 OK 20251210153512_drop_unused_gin_index.sql (5.44ms)12722026/09/21 14:02:49 OK 20251218171726_add_pins.sql (4.65ms)12732026/09/21 14:02:49 OK 20251218171726_add_pins.sql (4.74ms)1274--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.25s)1275=== CONT TestReadRedirectNar12762026/09/21 14:02:49 INFO Received create pin request method=POST path=/api/pins/myapp12772026/09/21 14:02:49 OK 20260628120000_add_object_size_and_stats.sql (18.85ms)12782026/09/21 14:02:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12792026/09/21 14:02:49 OK 20260628120000_add_object_size_and_stats.sql (20.05ms)12802026/09/21 14:02:49 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-62621-2691108556/TestPinProtectsFromGC954338770/001/store/i8c3gb7y8cp42fx5si8g38c2cdply2ay-pinned-file.txt narinfo_key=i8c3gb7y8cp42fx5si8g38c2cdply2ay.narinfo12812026/09/21 14:02:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures12822026/09/21 14:02:49 INFO Garbage collection started12832026/09/21 14:02:49 INFO Aborted multipart uploads count=012842026/09/21 14:02:49 WARN Force mode enabled - objects will be deleted immediately without grace period12852026/09/21 14:02:49 OK 20260905000000_add_claims.sql (11.47ms)12862026/09/21 14:02:49 OK 20260905000000_add_claims.sql (10.53ms)12872026/09/21 14:02:49 OK 20260920000000_drop_claims.sql (1.54ms)12882026/09/21 14:02:49 goose: successfully migrated database to version: 2026092000000012892026/09/21 14:02:49 OK 20260920000000_drop_claims.sql (1.26ms)12902026/09/21 14:02:49 goose: successfully migrated database to version: 2026092000000012912026/09/21 14:02:49 OK 1_commit_pending_closure.sql (1.03ms)12922026/09/21 14:02:49 OK 1_commit_pending_closure.sql (1.3ms)12932026/09/21 14:02:49 OK 2_object_stats_trigger.sql (303.33µs)12942026/09/21 14:02:49 goose: up to current file version: 212952026/09/21 14:02:49 OK 2_object_stats_trigger.sql (457.63µs)12962026/09/21 14:02:49 goose: up to current file version: 212972026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures12982026/09/21 14:02:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12992026/09/21 14:02:49 INFO Uploading akl4k69i77wgy5j7gf85im6kbs9024qi-shared-dep (136B)13002026/09/21 14:02:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13012026/09/21 14:02:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13022026/09/21 14:02:49 WARN Failed to register uploaded object key=akl4k69i77wgy5j7gf85im6kbs9024qi.ls error="server returned 404: 404 page not found\n"13032026/09/21 14:02:49 INFO Signed narinfos id=2 count=113042026/09/21 14:02:49 INFO Uploading 1 narinfos13052026/09/21 14:02:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13062026/09/21 14:02:49 WARN Failed to register uploaded object key=akl4k69i77wgy5j7gf85im6kbs9024qi.narinfo error="server returned 404: 404 page not found\n"1307=== NAME TestClientWithDependencies1308 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-62621-2691108556/TestClientWithDependencies1774448324/001/store/06vwnxz9h2ysqq156igz3bck58k4rmvb-test-script13092026/09/21 14:02:49 INFO Completed upload id=213102026/09/21 14:02:49 INFO Upload complete. (116ms)13112026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures13122026/09/21 14:02:49 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13132026/09/21 14:02:49 INFO Uploading akl4k69i77wgy5j7gf85im6kbs9024qi-shared-dep (136B)13142026/09/21 14:02:49 INFO Uploading harn6dfakd7gw2ck3d2gpg56fxsqf3d4-top (256B)13152026/09/21 14:02:49 WARN Failed to register uploaded object key=nar/1qzh25yrig84114fzn5yy1svf38yi3q9rvi175zn6192bagfw9hy.nar.zst error="server returned 404: 404 page not found\n"13162026/09/21 14:02:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13172026/09/21 14:02:49 WARN Failed to register uploaded object key=harn6dfakd7gw2ck3d2gpg56fxsqf3d4.ls error="server returned 404: 404 page not found\n"13182026/09/21 14:02:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign13192026/09/21 14:02:49 WARN Failed to register uploaded object key=akl4k69i77wgy5j7gf85im6kbs9024qi.ls error="server returned 404: 404 page not found\n"13202026/09/21 14:02:49 INFO Signed narinfos id=3 count=113212026/09/21 14:02:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13222026/09/21 14:02:49 INFO Signed narinfos id=1 count=113232026/09/21 14:02:49 INFO Uploading 2 narinfos13242026/09/21 14:02:49 WARN Failed to register uploaded object key=harn6dfakd7gw2ck3d2gpg56fxsqf3d4.narinfo error="server returned 404: 404 page not found\n"13252026/09/21 14:02:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13262026/09/21 14:02:49 WARN Failed to register uploaded object key=akl4k69i77wgy5j7gf85im6kbs9024qi.narinfo error="server returned 404: 404 page not found\n"13272026/09/21 14:02:49 INFO Completed upload id=113282026/09/21 14:02:49 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13292026/09/21 14:02:49 INFO Completed upload id=313302026/09/21 14:02:49 INFO Upload complete. (299ms)1331=== NAME TestClientSharedPathCommittedMidPush1332 client_integration_test.go:680: Retrieved narinfo from S3:1333 StorePath: /nix/var/nix/builds/nix-62621-2691108556/TestClientSharedPathCommittedMidPush2959810376/001/store/akl4k69i77wgy5j7gf85im6kbs9024qi-shared-dep1334 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1335 Compression: zstd1336 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821337 NarSize: 1361338 References: 1339 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1340 client_integration_test.go:680: Retrieved narinfo from S3:1341 StorePath: /nix/var/nix/builds/nix-62621-2691108556/TestClientSharedPathCommittedMidPush2959810376/001/store/harn6dfakd7gw2ck3d2gpg56fxsqf3d4-top1342 URL: nar/1qzh25yrig84114fzn5yy1svf38yi3q9rvi175zn6192bagfw9hy.nar.zst1343 Compression: zstd1344 NarHash: sha256:1qzh25yrig84114fzn5yy1svf38yi3q9rvi175zn6192bagfw9hy1345 NarSize: 2561346 References: /nix/var/nix/builds/nix-62621-2691108556/TestClientSharedPathCommittedMidPush2959810376/001/store/akl4k69i77wgy5j7gf85im6kbs9024qi-shared-dep1347 CA: text:sha256:1baig8gafzlmsv15skvbrhi58gfd6hmj0k9781wz4a1mjdrkqdr51348=== NAME TestClientWithDependencies1349 client_integration_test.go:615: Found 1 dependencies (including self)13502026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures1351--- PASS: TestClientSharedPathCommittedMidPush (1.94s)1352=== CONT TestReadProxyDisabled13532026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures13542026-09-21 14:02:49.911 UTC [62944] ERROR: relation "goose_db_version" does not exist at character 3613552026-09-21 14:02:49.911 UTC [62944] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/09/21 14:02:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13572026/09/21 14:02:49 INFO Received uploads request method=POST path=/api/pending_closures13582026/09/21 14:02:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13592026/09/21 14:02:49 INFO Uploading 06vwnxz9h2ysqq156igz3bck58k4rmvb-test-script (136B)13602026/09/21 14:02:49 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=013612026/09/21 14:02:49 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13622026/09/21 14:02:49 INFO Vacuumed table table=pending_closures13632026/09/21 14:02:49 WARN Failed to register uploaded object key=log/cbb9isd72pac9gvx5c2ijapk75nbincy-test-script.drv error="server returned 404: 404 page not found\n"13642026/09/21 14:02:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13652026/09/21 14:02:49 INFO Vacuumed table table=pending_objects13662026/09/21 14:02:49 INFO Signed narinfos id=1 count=113672026/09/21 14:02:49 INFO Uploading 1 narinfos13682026/09/21 14:02:49 WARN Failed to register uploaded object key=06vwnxz9h2ysqq156igz3bck58k4rmvb.ls error="server returned 404: 404 page not found\n"13692026/09/21 14:02:49 INFO Vacuumed table table=multipart_uploads13702026/09/21 14:02:49 INFO Vacuumed table table=closures13712026/09/21 14:02:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13722026/09/21 14:02:49 WARN Failed to register uploaded object key=06vwnxz9h2ysqq156igz3bck58k4rmvb.narinfo error="server returned 404: 404 page not found\n"13732026/09/21 14:02:50 INFO Vacuumed table table=objects13742026/09/21 14:02:50 INFO Completed upload id=113752026/09/21 14:02:50 INFO Upload complete. (113ms)1376=== NAME TestClientWithDependencies1377 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-62621-2691108556/TestClientWithDependencies1774448324/001/store) requires matching store prefix13782026/09/21 14:02:50 OK 20241026095416_initial_model.sql (83.4ms)13792026/09/21 14:02:50 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)13802026/09/21 14:02:50 OK 20251218171726_add_pins.sql (16.66ms)1381--- PASS: TestClientWithDependencies (1.83s)1382=== CONT TestService_ReadScope_PublicByDefault1383--- PASS: TestReadProxyRangeRequest (1.21s)1384=== CONT TestClientIntegration13852026/09/21 14:02:50 OK 20260628120000_add_object_size_and_stats.sql (30.75ms)13862026/09/21 14:02:50 OK 20260905000000_add_claims.sql (33.87ms)13872026/09/21 14:02:50 OK 20260920000000_drop_claims.sql (7.01ms)13882026/09/21 14:02:50 goose: successfully migrated database to version: 2026092000000013892026/09/21 14:02:50 OK 1_commit_pending_closure.sql (1.13ms)13902026/09/21 14:02:50 OK 2_object_stats_trigger.sql (200.5µs)13912026/09/21 14:02:50 goose: up to current file version: 21392--- PASS: TestReadRedirectUsesPublicS3URL (1.44s)1393=== CONT TestClientErrorHandling1394=== RUN TestClientErrorHandling/InvalidStorePath1395=== PAUSE TestClientErrorHandling/InvalidStorePath1396=== RUN TestClientErrorHandling/InvalidAuthToken1397=== PAUSE TestClientErrorHandling/InvalidAuthToken1398=== RUN TestClientErrorHandling/ServerNotAvailable1399=== PAUSE TestClientErrorHandling/ServerNotAvailable1400=== CONT TestClientCADerivations14012026/09/21 14:02:50 WARN Rate limiter enabled after throttle name=s3-test rate=514022026/09/21 14:02:50 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1403=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1404 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101405 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001406--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.07s)1407=== CONT TestCacheStatsHandler1408--- PASS: TestReadRedirectKeepsNarinfoProxied (1.19s)1409=== CONT TestCacheConfigHandler1410=== RUN TestCacheConfigHandler/full_config,_no_issuer1411=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1412=== RUN TestCacheConfigHandler/no_cache_url_configured1413=== PAUSE TestCacheConfigHandler/no_cache_url_configured1414=== RUN TestCacheConfigHandler/no_signing_keys1415=== PAUSE TestCacheConfigHandler/no_signing_keys1416=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1417=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1418=== CONT TestService_ReadAuthMiddleware14192026-09-21 14:02:50.425 UTC [62961] ERROR: relation "goose_db_version" does not exist at character 3614202026-09-21 14:02:50.425 UTC [62961] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14212026/09/21 14:02:50 OK 20241026095416_initial_model.sql (34.59ms)14222026/09/21 14:02:50 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)14232026/09/21 14:02:50 OK 20251218171726_add_pins.sql (2.3ms)14242026/09/21 14:02:50 OK 20260628120000_add_object_size_and_stats.sql (25.36ms)14252026/09/21 14:02:50 OK 20260905000000_add_claims.sql (19.71ms)14262026/09/21 14:02:50 OK 20260920000000_drop_claims.sql (1.81ms)14272026/09/21 14:02:50 goose: successfully migrated database to version: 2026092000000014282026/09/21 14:02:50 OK 1_commit_pending_closure.sql (2.01ms)14292026/09/21 14:02:50 OK 2_object_stats_trigger.sql (524.71µs)14302026/09/21 14:02:50 goose: up to current file version: 21431--- PASS: TestReadRedirectNar (1.11s)1432=== CONT TestService_RequireScope_OIDC14332026/09/21 14:02:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61271/oidc14342026/09/21 14:02:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14352026/09/21 14:02:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzJmMTAwY2MtNDE3MC00ZTlkLWE4NmQtMzdiOThhNTJlZmY2LjY2M2I4ODRlLWNiM2ItNDI2YS1hNzZkLTZiODNiMjRkNGRiMngxNzg5OTk5MzY5ODg3MjIyMDAw parts=121436--- PASS: TestRedundantMultipartUpload (2.38s)1437=== CONT TestService_AuthMiddleware_OIDC14382026/09/21 14:02:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61273/oidc14392026-09-21 14:02:51.114 UTC [62965] ERROR: relation "goose_db_version" does not exist at character 3614402026-09-21 14:02:51.114 UTC [62965] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14412026-09-21 14:02:51.133 UTC [62967] ERROR: relation "goose_db_version" does not exist at character 3614422026-09-21 14:02:51.133 UTC [62967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14432026-09-21 14:02:51.146 UTC [62968] ERROR: relation "goose_db_version" does not exist at character 3614442026-09-21 14:02:51.146 UTC [62968] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14452026/09/21 14:02:51 OK 20241026095416_initial_model.sql (25.56ms)14462026/09/21 14:02:51 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)14472026/09/21 14:02:51 OK 20251218171726_add_pins.sql (5.24ms)14482026/09/21 14:02:51 OK 20241026095416_initial_model.sql (23.19ms)14492026/09/21 14:02:51 OK 20260628120000_add_object_size_and_stats.sql (5.47ms)14502026/09/21 14:02:51 OK 20251210153512_drop_unused_gin_index.sql (934.33µs)14512026/09/21 14:02:51 OK 20251218171726_add_pins.sql (1.22ms)14522026/09/21 14:02:51 OK 20260905000000_add_claims.sql (2.31ms)14532026/09/21 14:02:51 OK 20241026095416_initial_model.sql (11.82ms)14542026/09/21 14:02:51 OK 20251210153512_drop_unused_gin_index.sql (379.63µs)14552026/09/21 14:02:51 OK 20260920000000_drop_claims.sql (1.03ms)14562026/09/21 14:02:51 goose: successfully migrated database to version: 2026092000000014572026/09/21 14:02:51 OK 20260628120000_add_object_size_and_stats.sql (2.28ms)14582026/09/21 14:02:51 OK 1_commit_pending_closure.sql (1.27ms)14592026/09/21 14:02:51 OK 2_object_stats_trigger.sql (217.17µs)14602026/09/21 14:02:51 goose: up to current file version: 214612026/09/21 14:02:51 OK 20251218171726_add_pins.sql (1.8ms)14622026/09/21 14:02:51 OK 20260905000000_add_claims.sql (1.68ms)14632026/09/21 14:02:51 OK 20260920000000_drop_claims.sql (586.42µs)14642026/09/21 14:02:51 goose: successfully migrated database to version: 2026092000000014652026/09/21 14:02:51 OK 1_commit_pending_closure.sql (965.21µs)14662026/09/21 14:02:51 OK 2_object_stats_trigger.sql (294.25µs)14672026/09/21 14:02:51 goose: up to current file version: 21468=== NAME TestOrphanedObjectsGCStressTest1469 orphaned_objects_gc_test.go:509: Stress test completed successfully:1470 orphaned_objects_gc_test.go:510: - Active objects preserved: 201471 orphaned_objects_gc_test.go:511: - Objects deleted: 2101472 orphaned_objects_gc_test.go:512: - Total GC'd: 2101473--- PASS: TestOrphanedObjectsGCStressTest (6.45s)1474=== CONT TestReadProxy40414752026/09/21 14:02:51 OK 20260628120000_add_object_size_and_stats.sql (28.62ms)14762026/09/21 14:02:51 OK 20260905000000_add_claims.sql (27.22ms)14772026/09/21 14:02:51 OK 20260920000000_drop_claims.sql (3.87ms)14782026/09/21 14:02:51 goose: successfully migrated database to version: 2026092000000014792026/09/21 14:02:51 OK 1_commit_pending_closure.sql (1.44ms)14802026/09/21 14:02:51 OK 2_object_stats_trigger.sql (220.25µs)14812026/09/21 14:02:51 goose: up to current file version: 214822026-09-21 14:02:51.372 UTC [62971] ERROR: relation "goose_db_version" does not exist at character 3614832026-09-21 14:02:51.372 UTC [62971] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1484--- PASS: TestReadProxyDisabled (1.50s)1485=== CONT TestReadProxyConditionalGet14862026-09-21 14:02:51.432 UTC [62974] ERROR: relation "goose_db_version" does not exist at character 3614872026-09-21 14:02:51.432 UTC [62974] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14882026/09/21 14:02:51 OK 20241026095416_initial_model.sql (78.99ms)14892026/09/21 14:02:51 OK 20251210153512_drop_unused_gin_index.sql (8.46ms)14902026/09/21 14:02:51 OK 20251218171726_add_pins.sql (13.8ms)14912026/09/21 14:02:51 OK 20241026095416_initial_model.sql (89.59ms)14922026/09/21 14:02:51 OK 20260628120000_add_object_size_and_stats.sql (31.99ms)1493--- PASS: TestService_ReadScope_PublicByDefault (1.50s)1494=== CONT TestReadProxyHead14952026/09/21 14:02:51 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)14962026/09/21 14:02:51 OK 20260905000000_add_claims.sql (7.79ms)14972026/09/21 14:02:51 OK 20251218171726_add_pins.sql (7.26ms)14982026/09/21 14:02:51 OK 20260920000000_drop_claims.sql (3.41ms)14992026/09/21 14:02:51 goose: successfully migrated database to version: 2026092000000015002026/09/21 14:02:51 OK 1_commit_pending_closure.sql (2.53ms)15012026/09/21 14:02:51 OK 2_object_stats_trigger.sql (562.04µs)15022026/09/21 14:02:51 goose: up to current file version: 215032026/09/21 14:02:51 OK 20260628120000_add_object_size_and_stats.sql (23.55ms)15042026-09-21 14:02:51.582 UTC [62979] ERROR: relation "goose_db_version" does not exist at character 3615052026-09-21 14:02:51.582 UTC [62979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15062026/09/21 14:02:51 OK 20260905000000_add_claims.sql (10.45ms)15072026/09/21 14:02:51 OK 20260920000000_drop_claims.sql (15.24ms)15082026/09/21 14:02:51 goose: successfully migrated database to version: 2026092000000015092026/09/21 14:02:51 OK 1_commit_pending_closure.sql (2.18ms)15102026/09/21 14:02:51 OK 2_object_stats_trigger.sql (400.46µs)15112026/09/21 14:02:51 goose: up to current file version: 215122026/09/21 14:02:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01513=== NAME TestPinProtectsFromGC1514 client_integration_test.go:794: Pin successfully protected closure from garbage collection15152026/09/21 14:02:51 OK 20241026095416_initial_model.sql (175.17ms)15162026/09/21 14:02:51 OK 20251210153512_drop_unused_gin_index.sql (13.22ms)1517--- PASS: TestPinProtectsFromGC (4.36s)1518=== CONT TestReadProxyInvalidPath15192026/09/21 14:02:51 OK 20251218171726_add_pins.sql (16.86ms)15202026/09/21 14:02:51 OK 20260628120000_add_object_size_and_stats.sql (42.79ms)15212026/09/21 14:02:51 OK 20260905000000_add_claims.sql (66.97ms)15222026/09/21 14:02:51 OK 20260920000000_drop_claims.sql (33.78ms)15232026/09/21 14:02:51 goose: successfully migrated database to version: 2026092000000015242026/09/21 14:02:51 OK 1_commit_pending_closure.sql (1.58ms)15252026/09/21 14:02:51 OK 2_object_stats_trigger.sql (337.25µs)15262026/09/21 14:02:51 goose: up to current file version: 21527=== NAME TestClientIntegration1528 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-62621-2691108556/TestClientIntegration4019536278/002/store/xl6czybb16jvdi095a2jn7li8szn7503-test-file.txt15292026-09-21 14:02:52.159 UTC [62990] ERROR: relation "goose_db_version" does not exist at character 3615302026-09-21 14:02:52.159 UTC [62990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15312026/09/21 14:02:52 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15322026/09/21 14:02:52 INFO Received uploads request method=POST path=/api/pending_closures15332026/09/21 14:02:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15342026/09/21 14:02:52 INFO Uploading xl6czybb16jvdi095a2jn7li8szn7503-test-file.txt (152B)15352026/09/21 14:02:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15362026/09/21 14:02:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15372026/09/21 14:02:52 WARN Failed to register uploaded object key=xl6czybb16jvdi095a2jn7li8szn7503.ls error="server returned 404: 404 page not found\n"15382026/09/21 14:02:52 INFO Signed narinfos id=1 count=115392026/09/21 14:02:52 INFO Uploading 1 narinfos15402026/09/21 14:02:52 OK 20241026095416_initial_model.sql (124.18ms)15412026/09/21 14:02:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15422026/09/21 14:02:52 WARN Failed to register uploaded object key=xl6czybb16jvdi095a2jn7li8szn7503.narinfo error="server returned 404: 404 page not found\n"1543--- PASS: TestCacheStatsHandler (2.10s)1544=== CONT TestServerTLSConfig1545=== RUN TestServerTLSConfig/no_client_CA1546=== PAUSE TestServerTLSConfig/no_client_CA1547=== RUN TestServerTLSConfig/missing_CA_file1548=== PAUSE TestServerTLSConfig/missing_CA_file1549=== RUN TestServerTLSConfig/not_a_PEM_file1550=== PAUSE TestServerTLSConfig/not_a_PEM_file1551=== CONT TestObjectStatsTrigger15522026/09/21 14:02:52 INFO Completed upload id=115532026/09/21 14:02:52 INFO Upload complete. (255ms)15542026/09/21 14:02:52 OK 20251210153512_drop_unused_gin_index.sql (68.76ms)15552026/09/21 14:02:52 OK 20251218171726_add_pins.sql (27.4ms)1556=== NAME TestClientCADerivations1557 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-62621-2691108556/TestClientCADerivations1196905695/001/store/xnaxrqns2qr04kbpwrx2xxf64i87jlsr-ca-test15582026/09/21 14:02:52 INFO All 1 paths already cached1559=== NAME TestClientIntegration1560 client_integration_test.go:312: Retrieved narinfo from S3:1561 StorePath: /nix/var/nix/builds/nix-62621-2691108556/TestClientIntegration4019536278/002/store/xl6czybb16jvdi095a2jn7li8szn7503-test-file.txt1562 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1563 Compression: zstd1564 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11565 NarSize: 1521566 References: 1567 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11568 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1569 client_integration_test.go:313: Decompressed .ls content (64 bytes):1570 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1571 client_integration_test.go:316: Testing garbage collection...15722026-09-21 14:02:52.434 UTC [63006] ERROR: relation "goose_db_version" does not exist at character 3615732026-09-21 14:02:52.434 UTC [63006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15742026/09/21 14:02:52 OK 20260628120000_add_object_size_and_stats.sql (16.58ms)15752026/09/21 14:02:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures15762026/09/21 14:02:52 INFO Garbage collection started15772026/09/21 14:02:52 INFO Aborted multipart uploads count=015782026/09/21 14:02:52 WARN Force mode enabled - objects will be deleted immediately without grace period15792026/09/21 14:02:52 OK 20260905000000_add_claims.sql (39.35ms)15802026-09-21 14:02:52.475 UTC [63007] ERROR: relation "goose_db_version" does not exist at character 3615812026-09-21 14:02:52.475 UTC [63007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1582=== NAME TestClientCADerivations1583 client_ca_test.go:139: Found 1 dependencies (including self)15842026/09/21 14:02:52 OK 20260920000000_drop_claims.sql (14.98ms)15852026/09/21 14:02:52 goose: successfully migrated database to version: 2026092000000015862026/09/21 14:02:52 OK 1_commit_pending_closure.sql (917.63µs)15872026/09/21 14:02:52 OK 2_object_stats_trigger.sql (234.63µs)15882026/09/21 14:02:52 goose: up to current file version: 21589--- PASS: TestService_ReadAuthMiddleware (2.13s)1590=== CONT TestMultipartCleanup15912026/09/21 14:02:52 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15922026/09/21 14:02:52 OK 20241026095416_initial_model.sql (104.59ms)15932026/09/21 14:02:52 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)15942026/09/21 14:02:52 OK 20251218171726_add_pins.sql (9.82ms)15952026/09/21 14:02:52 OK 20241026095416_initial_model.sql (68.68ms)15962026/09/21 14:02:52 OK 20251210153512_drop_unused_gin_index.sql (8.56ms)15972026/09/21 14:02:52 OK 20260628120000_add_object_size_and_stats.sql (15.73ms)15982026/09/21 14:02:52 INFO Received uploads request method=POST path=/api/pending_closures15992026/09/21 14:02:52 OK 20251218171726_add_pins.sql (11.89ms)16002026/09/21 14:02:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16012026/09/21 14:02:52 INFO Uploading xnaxrqns2qr04kbpwrx2xxf64i87jlsr-ca-test (144B)16022026/09/21 14:02:52 OK 20260905000000_add_claims.sql (21.6ms)16032026/09/21 14:02:52 OK 20260628120000_add_object_size_and_stats.sql (16.58ms)16042026/09/21 14:02:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16052026/09/21 14:02:52 WARN Failed to register uploaded object key=log/yrcx6lr9n7gh6ifgqf0vpda7xk3jxysy-ca-test.drv error="server returned 404: 404 page not found\n"16062026/09/21 14:02:52 OK 20260920000000_drop_claims.sql (34.34ms)16072026/09/21 14:02:52 goose: successfully migrated database to version: 2026092000000016082026/09/21 14:02:52 WARN Failed to register uploaded object key=xnaxrqns2qr04kbpwrx2xxf64i87jlsr.ls error="server returned 404: 404 page not found\n"16092026/09/21 14:02:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16102026/09/21 14:02:52 INFO Signed narinfos id=1 count=116112026/09/21 14:02:52 INFO Uploading 1 narinfos16122026/09/21 14:02:52 OK 1_commit_pending_closure.sql (1.49ms)16132026/09/21 14:02:52 OK 2_object_stats_trigger.sql (263.54µs)16142026/09/21 14:02:52 goose: up to current file version: 216152026/09/21 14:02:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=016162026/09/21 14:02:52 OK 20260905000000_add_claims.sql (45.74ms)16172026/09/21 14:02:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16182026/09/21 14:02:52 WARN Failed to register uploaded object key=xnaxrqns2qr04kbpwrx2xxf64i87jlsr.narinfo error="server returned 404: 404 page not found\n"16192026/09/21 14:02:52 INFO Vacuumed table table=pending_closures16202026/09/21 14:02:52 OK 20260920000000_drop_claims.sql (29.75ms)16212026/09/21 14:02:52 goose: successfully migrated database to version: 2026092000000016222026/09/21 14:02:52 INFO Completed upload id=116232026/09/21 14:02:52 INFO Upload complete. (192ms)1624=== NAME TestClientCADerivations1625 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-62621-2691108556/TestClientCADerivations1196905695/001/store/xnaxrqns2qr04kbpwrx2xxf64i87jlsr-ca-test1626 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1627 Compression: zstd1628 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1629 NarSize: 1441630 References: 1631 Deriver: /nix/var/nix/builds/nix-62621-2691108556/TestClientCADerivations1196905695/001/store/yrcx6lr9n7gh6ifgqf0vpda7xk3jxysy-ca-test.drv1632 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1633 client_ca_test.go:185: Checking for realisation files in S3...16342026/09/21 14:02:52 OK 1_commit_pending_closure.sql (1.39ms)1635 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1636 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16372026/09/21 14:02:52 OK 2_object_stats_trigger.sql (377µs)16382026/09/21 14:02:52 goose: up to current file version: 21639=== RUN TestService_RequireScope_OIDC/builder_may_write1640=== PAUSE TestService_RequireScope_OIDC/builder_may_write1641=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1642=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1643=== RUN TestService_RequireScope_OIDC/ops_may_admin1644=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1645=== RUN TestService_RequireScope_OIDC/ops_may_not_write1646=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1647=== RUN TestService_RequireScope_OIDC/reader_may_not_write1648=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1649=== RUN TestService_RequireScope_OIDC/static_token_may_admin1650=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1651=== RUN TestService_RequireScope_OIDC/static_token_may_write1652=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1653=== RUN TestService_RequireScope_OIDC/reader_may_read1654=== PAUSE TestService_RequireScope_OIDC/reader_may_read1655=== RUN TestService_RequireScope_OIDC/writer_implies_read1656=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1657=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1658=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1659=== CONT TestGCTaskStore_Fail1660--- PASS: TestGCTaskStore_Fail (0.00s)1661=== CONT TestGenerateLandingPage1662--- PASS: TestGenerateLandingPage (0.00s)1663=== CONT TestService_readinessHandler16642026/09/21 14:02:52 INFO Vacuumed table table=pending_objects16652026/09/21 14:02:52 INFO Vacuumed table table=multipart_uploads16662026/09/21 14:02:52 INFO Vacuumed table table=closures16672026/09/21 14:02:52 INFO Vacuumed table table=objects1668=== NAME TestClientCADerivations1669 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket34?endpoint=http://localhost:61180&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-62621-2691108556/TestClientCADerivations1196905695/001/store'1670 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116712026-09-21 14:02:52.828 UTC [63024] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-21 14:02:52.828 UTC [63024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1673--- PASS: TestClientCADerivations (2.61s)1674=== CONT TestService_healthCheckHandler1675--- PASS: TestReadProxy404 (1.77s)1676=== CONT TestGracefulShutdownDrainsInflight16772026/09/21 14:02:52 INFO Starting HTTP server address=127.0.0.1:6130116782026/09/21 14:02:52 INFO Shutdown signal received, draining in-flight requests timeout=10s1679--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1680=== CONT TestMetricsInventory16812026/09/21 14:02:53 OK 20241026095416_initial_model.sql (159.92ms)16822026/09/21 14:02:53 OK 20251210153512_drop_unused_gin_index.sql (7.98ms)16832026/09/21 14:02:53 OK 20251218171726_add_pins.sql (42.12ms)16842026/09/21 14:02:53 OK 20260628120000_add_object_size_and_stats.sql (27.5ms)16852026-09-21 14:02:53.153 UTC [63029] ERROR: relation "goose_db_version" does not exist at character 3616862026-09-21 14:02:53.153 UTC [63029] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16872026/09/21 14:02:53 OK 20260905000000_add_claims.sql (37.44ms)16882026/09/21 14:02:53 OK 20260920000000_drop_claims.sql (32.17ms)16892026/09/21 14:02:53 goose: successfully migrated database to version: 202609200000001690=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1691=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1692=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1693=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1694=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1695=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1696=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1697=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1698=== CONT TestService_NativeMTLS16992026/09/21 14:02:53 OK 1_commit_pending_closure.sql (4.95ms)17002026/09/21 14:02:53 OK 2_object_stats_trigger.sql (2.85ms)17012026/09/21 14:02:53 goose: up to current file version: 217022026/09/21 14:02:53 OK 20241026095416_initial_model.sql (217.59ms)17032026/09/21 14:02:53 OK 20251210153512_drop_unused_gin_index.sql (19.45ms)17042026-09-21 14:02:53.472 UTC [63032] ERROR: relation "goose_db_version" does not exist at character 3617052026-09-21 14:02:53.472 UTC [63032] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17062026/09/21 14:02:53 OK 20251218171726_add_pins.sql (19.99ms)1707--- PASS: TestReadProxyConditionalGet (2.10s)1708=== CONT TestNARDeduplicationMetadataUploadBug17092026/09/21 14:02:53 OK 20260628120000_add_object_size_and_stats.sql (27.49ms)17102026/09/21 14:02:53 OK 20260905000000_add_claims.sql (10.95ms)17112026/09/21 14:02:53 OK 20260920000000_drop_claims.sql (21.13ms)17122026/09/21 14:02:53 goose: successfully migrated database to version: 2026092000000017132026/09/21 14:02:53 OK 1_commit_pending_closure.sql (5.59ms)17142026/09/21 14:02:53 OK 2_object_stats_trigger.sql (433.63µs)17152026/09/21 14:02:53 goose: up to current file version: 217162026/09/21 14:02:53 OK 20241026095416_initial_model.sql (152.6ms)17172026/09/21 14:02:53 OK 20251210153512_drop_unused_gin_index.sql (17.9ms)17182026/09/21 14:02:53 OK 20251218171726_add_pins.sql (15.08ms)17192026/09/21 14:02:53 OK 20260628120000_add_object_size_and_stats.sql (21.98ms)17202026/09/21 14:02:53 OK 20260905000000_add_claims.sql (46.7ms)17212026/09/21 14:02:53 OK 20260920000000_drop_claims.sql (57.61ms)17222026/09/21 14:02:53 goose: successfully migrated database to version: 2026092000000017232026/09/21 14:02:53 OK 1_commit_pending_closure.sql (7.7ms)17242026/09/21 14:02:53 OK 2_object_stats_trigger.sql (1.32ms)17252026/09/21 14:02:53 goose: up to current file version: 21726--- PASS: TestReadProxyHead (2.31s)1727=== CONT TestGCTaskStore_CompletedAllowsNewTask1728--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1729=== CONT TestGCTaskStore_PhaseUpdates1730--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1731=== CONT TestGCTaskStore_GetReturnsLatest1732--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1733=== CONT TestGCTaskStore_GetEmpty1734--- PASS: TestGCTaskStore_GetEmpty (0.00s)1735=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17362026-09-21 14:02:54.105 UTC [63040] ERROR: relation "goose_db_version" does not exist at character 3617372026-09-21 14:02:54.105 UTC [63040] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1738--- PASS: TestReadProxyInvalidPath (2.30s)1739=== CONT TestReadProxyNarinfoAlreadyDecompressed17402026-09-21 14:02:54.150 UTC [63041] ERROR: relation "goose_db_version" does not exist at character 3617412026-09-21 14:02:54.150 UTC [63041] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17422026/09/21 14:02:54 OK 20241026095416_initial_model.sql (105.32ms)17432026/09/21 14:02:54 OK 20241026095416_initial_model.sql (101.83ms)17442026/09/21 14:02:54 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)17452026/09/21 14:02:54 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)17462026/09/21 14:02:54 OK 20251218171726_add_pins.sql (17.02ms)17472026/09/21 14:02:54 OK 20251218171726_add_pins.sql (18.46ms)17482026/09/21 14:02:54 OK 20260628120000_add_object_size_and_stats.sql (26.72ms)17492026/09/21 14:02:54 OK 20260628120000_add_object_size_and_stats.sql (34.83ms)17502026/09/21 14:02:54 OK 20260905000000_add_claims.sql (24.98ms)17512026/09/21 14:02:54 OK 20260920000000_drop_claims.sql (11.83ms)17522026/09/21 14:02:54 goose: successfully migrated database to version: 2026092000000017532026/09/21 14:02:54 OK 1_commit_pending_closure.sql (3.51ms)17542026/09/21 14:02:54 OK 2_object_stats_trigger.sql (737.42µs)17552026/09/21 14:02:54 goose: up to current file version: 217562026/09/21 14:02:54 OK 20260905000000_add_claims.sql (49.96ms)17572026-09-21 14:02:54.370 UTC [63045] ERROR: relation "goose_db_version" does not exist at character 3617582026-09-21 14:02:54.370 UTC [63045] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17592026-09-21 14:02:54.380 UTC [63044] ERROR: relation "goose_db_version" does not exist at character 3617602026-09-21 14:02:54.380 UTC [63044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17612026/09/21 14:02:54 OK 20260920000000_drop_claims.sql (17.03ms)17622026/09/21 14:02:54 goose: successfully migrated database to version: 2026092000000017632026/09/21 14:02:54 OK 1_commit_pending_closure.sql (3.1ms)17642026/09/21 14:02:54 OK 2_object_stats_trigger.sql (894.92µs)17652026/09/21 14:02:54 goose: up to current file version: 217662026/09/21 14:02:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01767=== NAME TestClientIntegration1768 client_integration_test.go:323: Objects in database after GC:1769 client_integration_test.go:323: Successfully deleted all objects with GC --force1770--- PASS: TestClientIntegration (4.49s)1771=== CONT TestReadProxyNarStreaming17722026/09/21 14:02:54 OK 20241026095416_initial_model.sql (172.87ms)17732026/09/21 14:02:54 OK 20251210153512_drop_unused_gin_index.sql (15.58ms)17742026/09/21 14:02:54 OK 20241026095416_initial_model.sql (178.81ms)17752026/09/21 14:02:54 OK 20251218171726_add_pins.sql (16.58ms)17762026/09/21 14:02:54 OK 20251210153512_drop_unused_gin_index.sql (16.08ms)17772026/09/21 14:02:54 INFO Received uploads request method=POST path=/api/pending_closures17782026/09/21 14:02:54 OK 20251218171726_add_pins.sql (24.02ms)17792026/09/21 14:02:54 OK 20260628120000_add_object_size_and_stats.sql (39.69ms)17802026/09/21 14:02:54 OK 20260628120000_add_object_size_and_stats.sql (51.67ms)17812026/09/21 14:02:54 OK 20260905000000_add_claims.sql (111.49ms)17822026/09/21 14:02:54 OK 20260905000000_add_claims.sql (86.78ms)17832026/09/21 14:02:54 OK 20260920000000_drop_claims.sql (21.38ms)17842026/09/21 14:02:54 goose: successfully migrated database to version: 2026092000000017852026/09/21 14:02:54 OK 20260920000000_drop_claims.sql (7.68ms)17862026/09/21 14:02:54 goose: successfully migrated database to version: 2026092000000017872026/09/21 14:02:54 OK 1_commit_pending_closure.sql (6.17ms)17882026/09/21 14:02:54 OK 2_object_stats_trigger.sql (1.08ms)17892026/09/21 14:02:54 goose: up to current file version: 217902026/09/21 14:02:54 OK 1_commit_pending_closure.sql (3.43ms)17912026/09/21 14:02:54 OK 2_object_stats_trigger.sql (612.17µs)17922026/09/21 14:02:54 goose: up to current file version: 217932026/09/21 14:02:54 INFO Received cleanup request method=DELETE path=/api/pending_closures17942026-09-21 14:02:54.861 UTC [63048] ERROR: relation "goose_db_version" does not exist at character 3617952026-09-21 14:02:54.861 UTC [63048] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17962026/09/21 14:02:54 INFO Aborted multipart uploads count=11797--- PASS: TestMultipartCleanup (2.37s)1798=== CONT TestReadProxyNarinfo17992026-09-21 14:02:54.935 UTC [63051] ERROR: relation "goose_db_version" does not exist at character 3618002026-09-21 14:02:54.935 UTC [63051] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18012026/09/21 14:02:54 OK 20241026095416_initial_model.sql (66.11ms)1802--- PASS: TestObjectStatsTrigger (2.59s)1803=== CONT TestService_AuthMiddleware_MTLSProxyHeader18042026/09/21 14:02:54 OK 20251210153512_drop_unused_gin_index.sql (8.83ms)18052026/09/21 14:02:54 OK 20251218171726_add_pins.sql (11.76ms)18062026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (20.37ms)18072026-09-21 14:02:55.014 UTC [63054] ERROR: relation "goose_db_version" does not exist at character 3618082026-09-21 14:02:55.014 UTC [63054] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18092026/09/21 14:02:55 OK 20260905000000_add_claims.sql (16.59ms)18102026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (14.45ms)18112026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000018122026/09/21 14:02:55 OK 20241026095416_initial_model.sql (76.08ms)18132026/09/21 14:02:55 OK 1_commit_pending_closure.sql (3.41ms)18142026/09/21 14:02:55 OK 2_object_stats_trigger.sql (444.46µs)18152026/09/21 14:02:55 goose: up to current file version: 218162026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (18.68ms)18172026/09/21 14:02:55 OK 20251218171726_add_pins.sql (15.1ms)18182026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (31.31ms)1819--- PASS: TestService_healthCheckHandler (2.27s)1820=== CONT TestParseSingleRange/none1821=== CONT TestParseSingleRange/open-ended1822=== CONT TestParseSingleRange/start_far_past_EOF1823=== CONT TestParseSingleRange/start_past_EOF1824=== CONT TestParseSingleRange/single_byte1825=== CONT TestParseSingleRange/suffix_exceeds_size1826=== CONT TestParseSingleRange/suffix1827=== CONT TestParseSingleRange/end_clamped_to_size1828=== CONT TestIsValidCachePath/narinfo1829=== CONT TestIsValidCachePath/index.html1830=== CONT TestIsValidCachePath/traversal_parent1831=== CONT TestIsValidCachePath/nix-cache-info1832=== CONT TestIsValidCachePath/realisation1833=== CONT TestIsValidCachePath/log1834=== CONT TestIsValidCachePath/ls1835=== CONT TestIsValidCachePath/nar_uncompressed1836=== CONT TestIsValidCachePath/nar_bz21837=== CONT TestIsValidCachePath/nar_xz1838=== CONT TestIsValidCachePath/nar_zst1839=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1840=== CONT TestIsValidCachePath/empty1841=== CONT TestIsValidCachePath/short_hash1842=== CONT TestIsValidCachePath/wrong_extension1843=== CONT TestIsValidCachePath/leading_slash1844=== CONT TestIsValidCachePath/invalid_char_u1845=== CONT TestIsValidCachePath/random_path1846=== CONT TestParseSingleRange/closed1847=== CONT TestParseSingleRange/malformed_both_empty1848=== CONT TestParseSingleRange/malformed_end_before_start1849=== CONT TestParseSingleRange/multi-range_ignored1850=== CONT TestParseSingleRange/malformed_no_dash1851=== CONT TestParseSingleRange/unknown_unit1852--- PASS: TestParseSingleRange (0.00s)1853 --- PASS: TestParseSingleRange/none (0.00s)1854 --- PASS: TestParseSingleRange/open-ended (0.00s)1855 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1856 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1857 --- PASS: TestParseSingleRange/single_byte (0.00s)1858 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1859 --- PASS: TestParseSingleRange/suffix (0.00s)1860 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1861 --- PASS: TestParseSingleRange/closed (0.00s)1862 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1863 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1864 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1865 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1866 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1867=== CONT TestIsValidCachePath/invalid_char_e1868=== CONT TestIsValidCachePath/traversal_in_middle1869--- PASS: TestIsValidCachePath (0.01s)1870 --- PASS: TestIsValidCachePath/narinfo (0.00s)1871 --- PASS: TestIsValidCachePath/index.html (0.00s)1872 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1873 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1874 --- PASS: TestIsValidCachePath/realisation (0.00s)1875 --- PASS: TestIsValidCachePath/log (0.00s)1876 --- PASS: TestIsValidCachePath/ls (0.00s)1877 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1878 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1879 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1880 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1881 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1882 --- PASS: TestIsValidCachePath/empty (0.00s)1883 --- PASS: TestIsValidCachePath/short_hash (0.00s)1884 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1885 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1886 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1887 --- PASS: TestIsValidCachePath/random_path (0.00s)1888 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1889 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1890=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18912026/09/21 14:02:55 INFO Received request for more parts method=POST path=/18922026/09/21 14:02:55 OK 20260905000000_add_claims.sql (8.38ms)18932026/09/21 14:02:55 OK 20241026095416_initial_model.sql (64.33ms)18942026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (4.45ms)18952026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000018962026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)18972026/09/21 14:02:55 OK 1_commit_pending_closure.sql (3.43ms)18982026/09/21 14:02:55 OK 2_object_stats_trigger.sql (917.58µs)18992026/09/21 14:02:55 goose: up to current file version: 219002026/09/21 14:02:55 OK 20251218171726_add_pins.sql (16.49ms)1901=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19022026/09/21 14:02:55 INFO Received uploads request method=POST path=/1903=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19042026/09/21 14:02:55 INFO Received complete multipart upload request method=POST path=/19052026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (16.53ms)19062026/09/21 14:02:55 OK 20260905000000_add_claims.sql (3.75ms)19072026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (8.64ms)19082026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000019092026/09/21 14:02:55 OK 1_commit_pending_closure.sql (1.08ms)19102026/09/21 14:02:55 OK 2_object_stats_trigger.sql (250.75µs)19112026/09/21 14:02:55 goose: up to current file version: 21912=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19132026/09/21 14:02:55 INFO Received uploads request method=POST path=/19142026-09-21 14:02:55.219 UTC [63055] ERROR: relation "goose_db_version" does not exist at character 3619152026-09-21 14:02:55.219 UTC [63055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19162026-09-21 14:02:55.293 UTC [63056] ERROR: relation "goose_db_version" does not exist at character 3619172026-09-21 14:02:55.293 UTC [63056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19182026/09/21 14:02:55 WARN readiness check failed error="closed pool"1919--- PASS: TestService_readinessHandler (2.58s)1920=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19212026/09/21 14:02:55 INFO Received complete multipart upload request method=POST path=/1922=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19232026/09/21 14:02:55 INFO Received request for more parts method=POST path=/1924=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19252026/09/21 14:02:55 INFO Received uploads request method=POST path=/1926--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1927 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1928 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1929 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1930 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1931=== CONT TestIsValidUploadKey/narinfo1932=== CONT TestIsValidUploadKey/realisation_plus_in_output1933=== CONT TestIsValidUploadKey/unknown_type1934=== CONT TestIsValidUploadKey/empty_key1935=== CONT TestIsValidUploadKey/absolute1936=== CONT TestIsValidUploadKey/traversal_nar1937=== CONT TestIsValidUploadKey/traversal1938=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1939=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1940=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1941=== CONT TestIsValidUploadKey/index.html1942=== CONT TestIsValidUploadKey/nix-cache-info1943=== CONT TestIsValidUploadKey/build_log_home-manager_file1944=== CONT TestIsValidUploadKey/realisation1945=== CONT TestIsValidUploadKey/build_log_equals1946=== CONT TestIsValidUploadKey/build_log_question_mark1947=== CONT TestIsValidUploadKey/build_log_plus_in_name1948=== CONT TestIsValidUploadKey/nar_plain1949=== CONT TestIsValidUploadKey/build_log1950=== CONT TestIsValidUploadKey/listing1951=== CONT TestIsValidUploadKey/nar_xz1952=== CONT TestIsValidUploadKey/nar_zst1953--- PASS: TestIsValidUploadKey (0.00s)1954 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1955 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1956 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1957 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1958 --- PASS: TestIsValidUploadKey/absolute (0.00s)1959 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1960 --- PASS: TestIsValidUploadKey/traversal (0.00s)1961 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1962 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1963 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1964 --- PASS: TestIsValidUploadKey/index.html (0.00s)1965 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1966 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1967 --- PASS: TestIsValidUploadKey/realisation (0.00s)1968 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1969 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1970 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1971 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1972 --- PASS: TestIsValidUploadKey/build_log (0.00s)1973 --- PASS: TestIsValidUploadKey/listing (0.00s)1974 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1975 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1976=== CONT TestProxyWriteTimeout/narinfo1977=== CONT TestProxyWriteTimeout/10_GiB_nar1978=== CONT TestProxyWriteTimeout/unknown_size1979=== CONT TestProxyWriteTimeout/1_GiB_nar1980--- PASS: TestProxyWriteTimeout (0.00s)1981 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1982 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1983 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1984 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1985=== CONT TestResolveDBConnectionString/flag_wins1986=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1987=== CONT TestResolveDBConnectionString/nothing_configured1988=== CONT TestResolveDBConnectionString/missing_file_is_an_error1989=== CONT TestResolveDBConnectionString/file_when_flag_empty1990=== CONT TestClientErrorHandling/InvalidStorePath19912026/09/21 14:02:55 OK 20241026095416_initial_model.sql (53.76ms)1992--- PASS: TestResolveDBConnectionString (0.01s)1993 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1994 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1995 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1996 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1997 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19982026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)19992026/09/21 14:02:55 OK 20251218171726_add_pins.sql (10.12ms)20002026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (11.57ms)20012026/09/21 14:02:55 OK 20260905000000_add_claims.sql (11.71ms)20022026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (6ms)20032026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000020042026/09/21 14:02:55 OK 1_commit_pending_closure.sql (979.08µs)20052026/09/21 14:02:55 OK 2_object_stats_trigger.sql (216.42µs)20062026/09/21 14:02:55 goose: up to current file version: 220072026/09/21 14:02:55 OK 20241026095416_initial_model.sql (30.79ms)20082026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (545.42µs)20092026/09/21 14:02:55 OK 20251218171726_add_pins.sql (11.12ms)20102026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (17.79ms)20112026/09/21 14:02:55 OK 20260905000000_add_claims.sql (20.61ms)20122026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (11.75ms)20132026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000020142026/09/21 14:02:55 OK 1_commit_pending_closure.sql (991.88µs)20152026/09/21 14:02:55 OK 2_object_stats_trigger.sql (204.83µs)20162026/09/21 14:02:55 goose: up to current file version: 22017--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2018 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2019 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2020 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)2021=== CONT TestClientErrorHandling/ServerNotAvailable2022--- PASS: TestMetricsInventory (2.44s)2023=== CONT TestClientErrorHandling/InvalidAuthToken20242026-09-21 14:02:55.470 UTC [63061] ERROR: relation "goose_db_version" does not exist at character 3620252026-09-21 14:02:55.470 UTC [63061] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20262026/09/21 14:02:55 OK 20241026095416_initial_model.sql (72.75ms)20272026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)20282026/09/21 14:02:55 OK 20251218171726_add_pins.sql (2.06ms)20292026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (11.88ms)20302026/09/21 14:02:55 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20312026/09/21 14:02:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"20322026/09/21 14:02:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2033--- PASS: TestService_NativeMTLS (2.41s)2034=== CONT TestCacheConfigHandler/full_config,_no_issuer2035=== CONT TestCacheConfigHandler/no_signing_keys2036=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2037=== CONT TestCacheConfigHandler/no_cache_url_configured2038--- PASS: TestCacheConfigHandler (0.00s)2039 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2040 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2041 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2042 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2043=== CONT TestServerTLSConfig/no_client_CA2044=== CONT TestServerTLSConfig/not_a_PEM_file20452026-09-21 14:02:55.603 UTC [63066] ERROR: relation "goose_db_version" does not exist at character 3620462026-09-21 14:02:55.603 UTC [63066] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20472026/09/21 14:02:55 OK 20260905000000_add_claims.sql (18.29ms)2048=== CONT TestServerTLSConfig/missing_CA_file2049--- PASS: TestServerTLSConfig (0.00s)2050 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2051 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2052 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2053=== CONT TestService_RequireScope_OIDC/builder_may_write2054=== CONT TestService_RequireScope_OIDC/static_token_may_admin2055=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2056=== CONT TestService_RequireScope_OIDC/writer_implies_read2057=== CONT TestService_RequireScope_OIDC/reader_may_read2058=== CONT TestService_RequireScope_OIDC/static_token_may_write2059=== CONT TestService_RequireScope_OIDC/ops_may_not_write2060=== CONT TestService_RequireScope_OIDC/reader_may_not_write2061=== CONT TestService_RequireScope_OIDC/ops_may_admin2062=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2063=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20642026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (1.83ms)20652026/09/21 14:02:55 goose: successfully migrated database to version: 202609200000002066--- PASS: TestService_RequireScope_OIDC (1.88s)2067 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2068 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2069 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2070 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2071 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2072 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2073 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2074 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20772026/09/21 14:02:55 OK 1_commit_pending_closure.sql (1.01ms)20782026/09/21 14:02:55 OK 2_object_stats_trigger.sql (296.63µs)20792026/09/21 14:02:55 goose: up to current file version: 22080=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20812026/09/21 14:02:55 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]2082=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2083=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20842026/09/21 14:02:55 WARN Authentication failed token_preview=eyJhbGciOi...hS2N-qBUOQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2085--- PASS: TestService_AuthMiddleware_OIDC (2.12s)2086 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2087 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2088 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2089 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20902026-09-21 14:02:55.661 UTC [63067] ERROR: relation "goose_db_version" does not exist at character 3620912026-09-21 14:02:55.661 UTC [63067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20922026/09/21 14:02:55 OK 20241026095416_initial_model.sql (63.42ms)20932026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (556.17µs)20942026/09/21 14:02:55 OK 20251218171726_add_pins.sql (1.76ms)20952026/09/21 14:02:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.822386ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20962026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (10.87ms)20972026/09/21 14:02:55 OK 20260905000000_add_claims.sql (11.52ms)20982026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (6.71ms)20992026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000021002026/09/21 14:02:55 OK 1_commit_pending_closure.sql (1.12ms)21012026/09/21 14:02:55 OK 2_object_stats_trigger.sql (241.38µs)21022026/09/21 14:02:55 goose: up to current file version: 221032026/09/21 14:02:55 OK 20241026095416_initial_model.sql (43.89ms)21042026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (7.26ms)21052026/09/21 14:02:55 OK 20251218171726_add_pins.sql (8.17ms)21062026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (10.61ms)21072026/09/21 14:02:55 OK 20260905000000_add_claims.sql (16.45ms)21082026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (1.31ms)21092026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000021102026/09/21 14:02:55 OK 1_commit_pending_closure.sql (1.29ms)21112026/09/21 14:02:55 OK 2_object_stats_trigger.sql (286.75µs)21122026/09/21 14:02:55 goose: up to current file version: 22113=== NAME TestNARDeduplicationMetadataUploadBug2114 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-62621-2691108556/TestNARDeduplicationMetadataUploadBug914582368/001/store/h73ymm3hagc9w3sxgvsdl03876l3k406-file1.txt21152026-09-21 14:02:55.887 UTC [63071] ERROR: relation "goose_db_version" does not exist at character 3621162026-09-21 14:02:55.887 UTC [63071] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21172026/09/21 14:02:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.390944ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21182026/09/21 14:02:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21192026/09/21 14:02:55 WARN mTLS auth: bound subjects configured but subject DN unavailable21202026/09/21 14:02:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2121--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.06s)21222026/09/21 14:02:55 OK 20241026095416_initial_model.sql (28.38ms)21232026/09/21 14:02:55 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)21242026/09/21 14:02:55 OK 20251218171726_add_pins.sql (5.51ms)21252026/09/21 14:02:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21262026/09/21 14:02:55 OK 20260628120000_add_object_size_and_stats.sql (8.21ms)21272026/09/21 14:02:55 OK 20260905000000_add_claims.sql (2.17ms)21282026/09/21 14:02:55 OK 20260920000000_drop_claims.sql (12.85ms)21292026/09/21 14:02:55 goose: successfully migrated database to version: 2026092000000021302026-09-21 14:02:55.965 UTC [63076] ERROR: relation "goose_db_version" does not exist at character 3621312026-09-21 14:02:55.965 UTC [63076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21322026/09/21 14:02:55 OK 1_commit_pending_closure.sql (798.25µs)21332026/09/21 14:02:55 OK 2_object_stats_trigger.sql (215.96µs)21342026/09/21 14:02:55 goose: up to current file version: 221352026/09/21 14:02:55 INFO Received uploads request method=POST path=/api/pending_closures21362026/09/21 14:02:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21372026/09/21 14:02:55 INFO Uploading h73ymm3hagc9w3sxgvsdl03876l3k406-file1.txt (160B)21382026/09/21 14:02:56 OK 20241026095416_initial_model.sql (28.3ms)21392026/09/21 14:02:56 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"21402026/09/21 14:02:56 OK 20251210153512_drop_unused_gin_index.sql (7.84ms)21412026/09/21 14:02:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21422026/09/21 14:02:56 INFO Signed narinfos id=1 count=121432026/09/21 14:02:56 INFO Uploading 1 narinfos21442026/09/21 14:02:56 WARN Failed to register uploaded object key=h73ymm3hagc9w3sxgvsdl03876l3k406.ls error="server returned 404: 404 page not found\n"21452026/09/21 14:02:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21462026/09/21 14:02:56 WARN Failed to register uploaded object key=h73ymm3hagc9w3sxgvsdl03876l3k406.narinfo error="server returned 404: 404 page not found\n"21472026/09/21 14:02:56 OK 20251218171726_add_pins.sql (8.82ms)21482026/09/21 14:02:56 INFO Completed upload id=121492026/09/21 14:02:56 INFO Upload complete. (120ms)2150=== NAME TestNARDeduplicationMetadataUploadBug2151 metadata_upload_test.go:54: Retrieved narinfo from S3:2152 StorePath: /nix/var/nix/builds/nix-62621-2691108556/TestNARDeduplicationMetadataUploadBug914582368/001/store/h73ymm3hagc9w3sxgvsdl03876l3k406-file1.txt2153 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2154 Compression: zstd2155 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2156 NarSize: 1602157 References: 2158 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2159 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2160 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2161 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}21622026/09/21 14:02:56 OK 20260628120000_add_object_size_and_stats.sql (9.18ms)21632026/09/21 14:02:56 OK 20260905000000_add_claims.sql (16.46ms)21642026/09/21 14:02:56 OK 20260920000000_drop_claims.sql (723.83µs)21652026/09/21 14:02:56 goose: successfully migrated database to version: 2026092000000021662026/09/21 14:02:56 OK 1_commit_pending_closure.sql (866.54µs)2167--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.94s)21682026/09/21 14:02:56 OK 2_object_stats_trigger.sql (216.42µs)21692026/09/21 14:02:56 goose: up to current file version: 22170=== NAME TestNARDeduplicationMetadataUploadBug2171 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-62621-2691108556/TestNARDeduplicationMetadataUploadBug914582368/001/store/m63rbxpy3rxiy3ahf9shb57qqqi9mpij-file2.txt21722026/09/21 14:02:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2173--- PASS: TestReadProxyNarStreaming (1.60s)21742026/09/21 14:02:56 INFO Received uploads request method=POST path=/api/pending_closures21752026/09/21 14:02:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21762026/09/21 14:02:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21772026/09/21 14:02:56 INFO Signed narinfos id=2 count=121782026/09/21 14:02:56 INFO Uploading 1 narinfos21792026/09/21 14:02:56 WARN Failed to register uploaded object key=m63rbxpy3rxiy3ahf9shb57qqqi9mpij.ls error="server returned 404: 404 page not found\n"21802026/09/21 14:02:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21812026/09/21 14:02:56 WARN Failed to register uploaded object key=m63rbxpy3rxiy3ahf9shb57qqqi9mpij.narinfo error="server returned 404: 404 page not found\n"21822026/09/21 14:02:56 INFO Completed upload id=221832026/09/21 14:02:56 INFO Upload complete. (96ms)2184=== NAME TestNARDeduplicationMetadataUploadBug2185 metadata_upload_test.go:76: Retrieved narinfo from S3:2186 StorePath: /nix/var/nix/builds/nix-62621-2691108556/TestNARDeduplicationMetadataUploadBug914582368/001/store/m63rbxpy3rxiy3ahf9shb57qqqi9mpij-file2.txt2187 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2188 Compression: zstd2189 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2190 NarSize: 1602191 References: 2192 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2193 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2194 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2195 {"version":1,"root":{"type":"regular","size":44}}2196--- PASS: TestNARDeduplicationMetadataUploadBug (2.74s)2197--- PASS: TestReadProxyNarinfo (1.37s)21982026/09/21 14:02:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=868.566988ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2199--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.35s)22002026/09/21 14:02:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22012026/09/21 14:02:56 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22022026/09/21 14:02:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22032026/09/21 14:02:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.689954535s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22042026/09/21 14:02:58 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22052026/09/21 14:02:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.509755ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22062026/09/21 14:02:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.999242ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22072026/09/21 14:02:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=748.109009ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/09/21 14:03:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.731418381s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/09/21 14:03:02 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"22102026/09/21 14:03:02 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22112026/09/21 14:03:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.133032ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22122026/09/21 14:03:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.501155ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22132026/09/21 14:03:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=813.202419ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22142026/09/21 14:03:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.612150369s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2215--- PASS: TestClientErrorHandling (0.00s)2216 --- PASS: TestClientErrorHandling/InvalidStorePath (1.19s)2217 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.20s)2218 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.93s)2219PASS2220{"timestamp":"2026-09-21T14:03:05.384989Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61213","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}22212026-09-21 14:03:05.483 UTC [62665] LOG: received smart shutdown request22222026-09-21 14:03:05.484 UTC [62665] LOG: background worker "logical replication launcher" (PID 62675) exited with exit code 122232026-09-21 14:03:05.492 UTC [62670] LOG: shutting down22242026-09-21 14:03:05.492 UTC [62670] LOG: checkpoint starting: shutdown immediate22252026-09-21 14:03:06.596 UTC [62670] LOG: checkpoint complete: wrote 12965 buffers (79.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.753 s, sync=0.319 s, total=1.104 s; sync files=18738, longest=0.001 s, average=0.001 s; distance=260139 kB, estimate=260139 kB; lsn=0/11597E60, redo lsn=0/11597E6022262026-09-21 14:03:06.600 UTC [62665] LOG: database system is shut down2227Running OIDC tests...2228=== RUN TestGlobMatch2229=== PAUSE TestGlobMatch2230=== RUN TestAudienceForIssuer2231=== PAUSE TestAudienceForIssuer2232=== RUN TestValidateToken_ValidToken2233=== PAUSE TestValidateToken_ValidToken2234=== RUN TestValidateToken_WrongAudience2235=== PAUSE TestValidateToken_WrongAudience2236=== RUN TestValidateToken_Expired2237=== PAUSE TestValidateToken_Expired2238=== RUN TestValidateToken_BoundClaimsMismatch2239=== PAUSE TestValidateToken_BoundClaimsMismatch2240=== RUN TestValidateToken_BoundSubjectMismatch2241=== PAUSE TestValidateToken_BoundSubjectMismatch2242=== RUN TestValidateToken_MultipleProviders2243=== PAUSE TestValidateToken_MultipleProviders2244=== RUN TestValidateToken_NoMatchingProvider2245=== PAUSE TestValidateToken_NoMatchingProvider2246=== RUN TestValidateToken_KubernetesServiceAccount2247=== PAUSE TestValidateToken_KubernetesServiceAccount2248=== RUN TestNewValidator_KubernetesRequiresCA2249=== PAUSE TestNewValidator_KubernetesRequiresCA2250=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2251=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2252=== RUN TestScopes_LegacyProviderDefaultsToWrite2253=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2254=== RUN TestScopes_Rules2255=== PAUSE TestScopes_Rules2256=== RUN TestScopes_ConfigValidation2257=== PAUSE TestScopes_ConfigValidation2258=== CONT TestGlobMatch2259=== CONT TestValidateToken_Expired2260=== CONT TestScopes_LegacyProviderDefaultsToWrite2261=== CONT TestValidateToken_NoMatchingProvider2262=== CONT TestValidateToken_BoundSubjectMismatch2263=== CONT TestValidateToken_BoundClaimsMismatch2264=== RUN TestGlobMatch/foo_foo2265=== CONT TestValidateToken_WrongAudience2266=== PAUSE TestGlobMatch/foo_foo2267=== CONT TestValidateToken_ValidToken2268=== RUN TestGlobMatch/foo_bar2269=== PAUSE TestGlobMatch/foo_bar2270=== RUN TestGlobMatch/*_2271=== PAUSE TestGlobMatch/*_2272=== RUN TestGlobMatch/*_anything2273=== PAUSE TestGlobMatch/*_anything2274=== RUN TestGlobMatch/foo*_foo2275=== PAUSE TestGlobMatch/foo*_foo2276=== RUN TestGlobMatch/foo*_foobar2277=== PAUSE TestGlobMatch/foo*_foobar2278=== RUN TestGlobMatch/foo*_bar2279=== PAUSE TestGlobMatch/foo*_bar2280=== RUN TestGlobMatch/*bar_bar2281=== PAUSE TestGlobMatch/*bar_bar2282=== RUN TestGlobMatch/*bar_foobar2283=== PAUSE TestGlobMatch/*bar_foobar2284=== RUN TestGlobMatch/*bar_foo2285=== PAUSE TestGlobMatch/*bar_foo2286=== RUN TestGlobMatch/foo*bar_foobar2287=== PAUSE TestGlobMatch/foo*bar_foobar2288=== RUN TestGlobMatch/foo*bar_foo123bar2289=== PAUSE TestGlobMatch/foo*bar_foo123bar2290=== RUN TestGlobMatch/foo*bar_foobarbaz2291=== CONT TestAudienceForIssuer2292--- PASS: TestAudienceForIssuer (0.00s)2293=== CONT TestScopes_ConfigValidation2294=== CONT TestValidateToken_MultipleProviders2295=== PAUSE TestGlobMatch/foo*bar_foobarbaz2296=== RUN TestGlobMatch/*/*_foo/bar2297=== PAUSE TestGlobMatch/*/*_foo/bar2298=== RUN TestGlobMatch/*/*_foo2299=== PAUSE TestGlobMatch/*/*_foo2300=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2301=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2302=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02303=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02304=== RUN TestGlobMatch/refs/*/main_refs/heads/main2305=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2306=== RUN TestGlobMatch/fo?_foo2307=== PAUSE TestGlobMatch/fo?_foo2308=== RUN TestGlobMatch/fo?_fo2309=== PAUSE TestGlobMatch/fo?_fo2310=== RUN TestGlobMatch/fo?_fooo2311=== PAUSE TestGlobMatch/fo?_fooo2312=== RUN TestGlobMatch/?oo_foo2313=== PAUSE TestGlobMatch/?oo_foo2314=== RUN TestGlobMatch/?oo_boo2315=== PAUSE TestGlobMatch/?oo_boo2316=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2317=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2318=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2319=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2320=== CONT TestNewValidator_KubernetesRequiresCA23212026/09/21 14:03:07 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61385/oidc23222026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61380/oidc23232026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61383/oidc23242026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61387/oidc23252026/09/21 14:03:07 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61386/oidc23262026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61382/oidc23272026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61384/oidc2328--- PASS: TestScopes_ConfigValidation (0.00s)2329=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23302026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61381/oidc23312026/09/21 14:03:07 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:61389/oidc2332--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2333=== CONT TestValidateToken_KubernetesServiceAccount2334--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2335=== CONT TestScopes_Rules2336--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2337--- PASS: TestValidateToken_Expired (0.01s)2338--- PASS: TestValidateToken_WrongAudience (0.01s)2339=== CONT TestGlobMatch/foo_foo2340=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2341=== CONT TestGlobMatch/?oo_boo2342=== CONT TestGlobMatch/*/*_foo/bar2343=== CONT TestGlobMatch/?oo_foo2344=== CONT TestGlobMatch/fo?_fooo2345=== CONT TestGlobMatch/fo?_foo2346=== CONT TestGlobMatch/refs/*/main_refs/heads/main2347=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2348=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02349=== CONT TestGlobMatch/fo?_fo2350=== CONT TestGlobMatch/*/*_foo2351=== CONT TestGlobMatch/foo*bar_foobarbaz2352=== CONT TestGlobMatch/foo*bar_foo123bar2353=== CONT TestGlobMatch/foo*bar_foobar2354=== CONT TestGlobMatch/*bar_foo2355=== CONT TestGlobMatch/*bar_foobar2356=== CONT TestGlobMatch/foo*_foo2357=== CONT TestGlobMatch/foo*_bar2358=== CONT TestGlobMatch/foo*_foobar2359=== CONT TestGlobMatch/*_2360=== CONT TestGlobMatch/*_anything2361=== CONT TestGlobMatch/foo_bar2362=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2363=== CONT TestGlobMatch/*bar_bar2364--- PASS: TestGlobMatch (0.00s)2365 --- PASS: TestGlobMatch/foo_foo (0.00s)2366 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2367 --- PASS: TestGlobMatch/?oo_boo (0.00s)2368 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2369 --- PASS: TestGlobMatch/?oo_foo (0.00s)2370 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2371 --- PASS: TestGlobMatch/fo?_foo (0.00s)2372 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2373 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2374 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2375 --- PASS: TestGlobMatch/fo?_fo (0.00s)2376 --- PASS: TestGlobMatch/*/*_foo (0.00s)2377 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2378 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2379 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2380 --- PASS: TestGlobMatch/*bar_foo (0.00s)2381 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2382 --- PASS: TestGlobMatch/foo*_foo (0.00s)2383 --- PASS: TestGlobMatch/foo*_bar (0.00s)2384 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2385 --- PASS: TestGlobMatch/*_ (0.00s)2386 --- PASS: TestGlobMatch/*_anything (0.00s)2387 --- PASS: TestGlobMatch/foo_bar (0.00s)2388 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2389 --- PASS: TestGlobMatch/*bar_bar (0.00s)23902026/09/21 14:03:07 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232391--- PASS: TestValidateToken_ValidToken (0.01s)2392--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)23932026/09/21 14:03:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61402/oidc2394--- PASS: TestValidateToken_MultipleProviders (0.01s)23952026/09/21 14:03:07 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6140323962026/09/21 14:03:07 http: TLS handshake error from 127.0.0.1:61395: remote error: tls: bad certificate2397--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2398--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2399--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2400--- PASS: TestScopes_Rules (0.01s)2401PASS2402Running hook tests...2403=== RUN TestSendPathsEmpty2404=== PAUSE TestSendPathsEmpty2405=== RUN TestQueueEnqueueAndFetch2406=== PAUSE TestQueueEnqueueAndFetch2407=== RUN TestQueueDeduplication2408=== PAUSE TestQueueDeduplication2409=== RUN TestQueueRemove2410=== PAUSE TestQueueRemove2411=== RUN TestQueueFetchBatchLimit2412=== PAUSE TestQueueFetchBatchLimit2413=== RUN TestQueueRetryMovesToBack2414=== PAUSE TestQueueRetryMovesToBack2415=== RUN TestQueueFetchRemoveLifecycle2416=== PAUSE TestQueueFetchRemoveLifecycle2417=== RUN TestQueueConcurrentWriters2418=== PAUSE TestQueueConcurrentWriters2419=== RUN TestQueueRemoveLargeClosure2420=== PAUSE TestQueueRemoveLargeClosure2421=== RUN TestServerClientIntegration2422=== PAUSE TestServerClientIntegration2423=== RUN TestServerQueueError2424=== PAUSE TestServerQueueError2425=== RUN TestGetListenerSocketActivation2426 server_test.go:210: === RUN TestGetListenerSocketActivation2427 --- PASS: TestGetListenerSocketActivation (0.00s)2428 PASS2429 2430--- PASS: TestGetListenerSocketActivation (0.01s)2431=== RUN TestDrainIsolatesPoisonPath2432=== PAUSE TestDrainIsolatesPoisonPath2433=== RUN TestRunNotBlockedByPoisonHead2434=== PAUSE TestRunNotBlockedByPoisonHead2435=== RUN TestDrainGivesUpWhenServerDown2436=== PAUSE TestDrainGivesUpWhenServerDown2437=== RUN TestFailedPathPrunedByLaterClosure2438=== PAUSE TestFailedPathPrunedByLaterClosure2439=== RUN TestWorkerUploadsAndRemoves2440=== PAUSE TestWorkerUploadsAndRemoves2441=== RUN TestWorkerSkipsGCdPaths2442=== PAUSE TestWorkerSkipsGCdPaths2443=== RUN TestWorkerPrunesClosureDeps2444=== PAUSE TestWorkerPrunesClosureDeps2445=== RUN TestDrainTimeout2446=== PAUSE TestDrainTimeout2447=== CONT TestSendPathsEmpty2448=== CONT TestServerQueueError2449=== CONT TestWorkerUploadsAndRemoves2450--- PASS: TestSendPathsEmpty (0.00s)2451=== CONT TestServerClientIntegration2452=== CONT TestQueueRemoveLargeClosure2453=== CONT TestQueueConcurrentWriters2454=== CONT TestQueueRemove2455=== CONT TestQueueDeduplication2456=== CONT TestQueueEnqueueAndFetch2457=== CONT TestDrainGivesUpWhenServerDown2458=== CONT TestFailedPathPrunedByLaterClosure24592026/09/21 14:03:07 ERROR Failed to queue paths error="permission denied" count=12460--- PASS: TestServerQueueError (0.00s)2461=== CONT TestRunNotBlockedByPoisonHead2462--- PASS: TestServerClientIntegration (0.00s)2463=== CONT TestDrainIsolatesPoisonPath24642026/09/21 14:03:07 INFO Uploading batch count=124652026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=124662026/09/21 14:03:07 INFO Uploading batch count=424672026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=42468--- PASS: TestQueueEnqueueAndFetch (0.01s)2469=== CONT TestQueueFetchBatchLimit24702026/09/21 14:03:07 INFO Upload queue status pending=224712026/09/21 14:03:07 INFO Uploading batch count=224722026/09/21 14:03:07 INFO Uploading batch count=224732026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=224742026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainGivesUpWhenServerDown2052346156/002/a24752026/09/21 14:03:07 INFO Uploading batch count=124762026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainGivesUpWhenServerDown2052346156/002/b24772026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainIsolatesPoisonPath117249105/002/bbb2478--- PASS: TestQueueDeduplication (0.01s)2479=== CONT TestQueueFetchRemoveLifecycle24802026/09/21 14:03:07 INFO Uploading batch count=124812026/09/21 14:03:07 INFO Uploading batch count=224822026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=224832026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainGivesUpWhenServerDown2052346156/002/c24842026/09/21 14:03:07 INFO Upload queue status pending=324852026/09/21 14:03:07 INFO Uploading batch count=124862026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=124872026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainGivesUpWhenServerDown2052346156/002/d24882026/09/21 14:03:07 INFO Uploading batch count=124892026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=12490--- PASS: TestQueueRemove (0.01s)2491=== CONT TestQueueRetryMovesToBack24922026/09/21 14:03:07 INFO Uploading batch count=224932026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=224942026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainGivesUpWhenServerDown2052346156/002/e24952026/09/21 14:03:07 INFO Uploading batch count=124962026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=124972026/09/21 14:03:07 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-62621-2691108556/TestDrainGivesUpWhenServerDown2052346156/002/f24982026/09/21 14:03:07 INFO Uploading batch count=124992026/09/21 14:03:07 ERROR Upload failed error="upload failed" count=125002026/09/21 14:03:07 ERROR Drain finished with paths left in queue remaining=102501--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2502=== CONT TestWorkerPrunesClosureDeps25032026/09/21 14:03:07 ERROR Drain finished with paths left in queue remaining=12504--- PASS: TestQueueFetchBatchLimit (0.00s)2505=== CONT TestDrainTimeout2506--- PASS: TestDrainIsolatesPoisonPath (0.01s)2507=== CONT TestWorkerSkipsGCdPaths2508--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2509--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2510--- PASS: TestQueueRetryMovesToBack (0.00s)25112026/09/21 14:03:07 INFO Uploading batch count=225122026/09/21 14:03:07 INFO Upload queue status pending=225132026/09/21 14:03:07 INFO Uploading batch count=125142026/09/21 14:03:07 INFO Upload queue status pending=225152026/09/21 14:03:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-62621-2691108556/TestWorkerSkipsGCdPaths131879214/002/nonexistent25162026/09/21 14:03:07 INFO Uploading batch count=12517--- PASS: TestWorkerUploadsAndRemoves (0.03s)2518--- PASS: TestWorkerPrunesClosureDeps (0.02s)2519--- PASS: TestWorkerSkipsGCdPaths (0.02s)2520--- PASS: TestQueueRemoveLargeClosure (0.06s)2521--- PASS: TestQueueConcurrentWriters (0.13s)25222026/09/21 14:03:08 ERROR Upload failed error="context deadline exceeded" count=225232026/09/21 14:03:08 ERROR Drain finished with paths left in queue remaining=42524--- PASS: TestDrainTimeout (0.21s)25252026/09/21 14:03:08 INFO Uploading batch count=125262026/09/21 14:03:08 INFO Uploading batch count=125272026/09/21 14:03:08 INFO Uploading batch count=125282026/09/21 14:03:08 ERROR Upload failed error="upload failed" count=125292026/09/21 14:03:08 INFO Uploading batch count=125302026/09/21 14:03:08 ERROR Upload failed error="upload failed" count=125312026/09/21 14:03:08 INFO Uploading batch count=125322026/09/21 14:03:08 ERROR Upload failed error="upload failed" count=125332026/09/21 14:03:08 INFO Uploading batch count=125342026/09/21 14:03:08 ERROR Upload failed error="upload failed" count=125352026/09/21 14:03:08 ERROR Drain finished with paths left in queue remaining=12536--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2537PASS

succeeded niks3-go-unit-tests checks.aarch64-darwin.go-unit-tests · build #235 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-darwin.go-unit-tests` · build #235 · raw