niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #230
· 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.05s)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 TestEncodeNixBase32WithRealHash93--- PASS: TestEncodeNixBase32WithRealHash (0.00s)94=== CONT TestGetStorePathHash95=== RUN TestGetStorePathHash/valid_store_path96=== PAUSE TestGetStorePathHash/valid_store_path97=== RUN TestGetStorePathHash/basename_without_hyphen_should_error98=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error99=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error100=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error101=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error102=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error103=== CONT TestResolveStorePath104=== CONT TestConvertHashToNix32105=== RUN TestConvertHashToNix32/SRI_format_to_Nix32106=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32107=== RUN TestConvertHashToNix32/already_Nix32_format108=== PAUSE TestConvertHashToNix32/already_Nix32_format109=== RUN TestConvertHashToNix32/invalid_format110=== PAUSE TestConvertHashToNix32/invalid_format111=== CONT TestStaticToken112--- PASS: TestStaticToken (0.00s)113=== CONT TestScriptTokenEmptyCommand114--- PASS: TestScriptTokenEmptyCommand (0.00s)115=== CONT TestScriptTokenScriptFails116=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess117=== CONT TestRateLimiterFeedback118=== RUN TestRateLimiterFeedback/429_enables_limiter119=== PAUSE TestRateLimiterFeedback/429_enables_limiter120=== RUN TestRateLimiterFeedback/503_enables_limiter121=== PAUSE TestRateLimiterFeedback/503_enables_limiter122=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter123=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter124=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter125=== CONT TestPathInfoCACompatibility126=== RUN TestPathInfoCACompatibility/null_ca_field127=== CONT TestParsePathInfoJSONMultiplePaths128=== PAUSE TestPathInfoCACompatibility/null_ca_field129=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths130=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths132=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths133=== CONT TestParsePathInfoJSON134=== RUN TestParsePathInfoJSON/Nix_format135=== PAUSE TestParsePathInfoJSON/Nix_format136=== RUN TestParsePathInfoJSON/Lix_format137=== PAUSE TestParsePathInfoJSON/Lix_format138=== RUN TestParsePathInfoJSON/empty_input139=== PAUSE TestParsePathInfoJSON/empty_input140=== RUN TestParsePathInfoJSON/whitespace_only141=== PAUSE TestParsePathInfoJSON/whitespace_only142=== RUN TestParsePathInfoJSON/invalid_JSON143=== CONT TestScriptTokenBadJSON1442026/09/20 19:22:11 WARN Rate limiter enabled after throttle name=server-test rate=5145=== PAUSE TestParsePathInfoJSON/invalid_JSON146=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter147=== CONT TestScriptTokenEmptyToken148=== CONT TestPathInfoHashCompatibility149=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)151=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon152=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon153=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI154=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI155=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512156=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512157=== RUN TestPathInfoCACompatibility/old_string_format_-_text158=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text159=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive160=== CONT TestScriptTokenNoExpiryRerunsEveryCall161--- PASS: TestResolveStorePath (0.00s)162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive163=== RUN TestPathInfoCACompatibility/new_structured_format_-_text164=== CONT TestScriptTokenCachesUntilRefresh165=== CONT TestFileTokenEmpty1662026/09/20 19:22:11 WARN Rate limiter enabled after throttle name=server-test rate=51672026/09/20 19:22:11 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59481168=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text169=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method170=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method171=== CONT TestFileTokenMissing1722026/09/20 19:22:12 WARN Rate limiter backed off name=server-test rate=51732026/09/20 19:22:12 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59481174--- PASS: TestFileTokenMissing (0.00s)175--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)176=== CONT TestStreamPushGivesUpOnDeadServer177--- PASS: TestFileTokenEmpty (0.00s)178=== CONT TestSetClientTLSErrors179--- PASS: TestScriptTokenScriptFails (0.00s)180=== CONT TestSetClientTLSDoesNotMutateDefaultTransport181--- PASS: TestDoServerRequestAttachesToken (0.01s)182=== CONT TestSetClientTLS1832026/09/20 19:22:12 ERROR Upload failed error="connection refused" count=20184=== CONT TestFileTokenReadsAndCaches1852026/09/20 19:22:12 ERROR Server seems unavailable, giving up on batch untried=17186--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)187=== CONT TestStreamPushRequestLine188--- PASS: TestFileTokenReadsAndCaches (0.00s)189=== CONT TestUploadMultipart_SupersededByPeer190=== RUN TestUploadMultipart_SupersededByPeer/exists191=== PAUSE TestUploadMultipart_SupersededByPeer/exists192=== RUN TestUploadMultipart_SupersededByPeer/missing193=== PAUSE TestUploadMultipart_SupersededByPeer/missing1942026/09/20 19:22:12 ERROR Upload failed error=boom count=1195=== CONT TestEncodeNixBase32196=== RUN TestEncodeNixBase32/test_string_hash197=== PAUSE TestEncodeNixBase32/test_string_hash198=== RUN TestEncodeNixBase32/empty_input199=== PAUSE TestEncodeNixBase32/empty_input200=== CONT TestDumpPathWriterError201=== RUN TestSetClientTLSErrors/missing_cert_file202=== PAUSE TestSetClientTLSErrors/missing_cert_file203=== RUN TestSetClientTLSErrors/missing_key_file204=== PAUSE TestSetClientTLSErrors/missing_key_file205=== RUN TestSetClientTLSErrors/missing_ca_file206=== PAUSE TestSetClientTLSErrors/missing_ca_file207=== RUN TestSetClientTLSErrors/invalid_ca_file208=== PAUSE TestSetClientTLSErrors/invalid_ca_file209=== CONT TestDumpPathSingleFile210--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)211=== CONT TestDumpPathMatchesNix212=== 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 TestStreamPushReportsEveryPath219--- PASS: TestStreamPushReportsEveryPath (0.00s)220=== CONT TestStreamPushIsolatesFailures2212026/09/20 19:22:12 ERROR Upload failed error="bad path" count=3222--- PASS: TestStreamPushIsolatesFailures (0.00s)223=== CONT TestStreamPushBatchesUnderLoad224--- PASS: TestScriptTokenEmptyToken (0.01s)225=== CONT TestFilterOversizedClosures226=== RUN TestFilterOversizedClosures/no_limit_keeps_everything227=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything228=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped229=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== RUN TestFilterOversizedClosures/all_closures_skipped231=== PAUSE TestFilterOversizedClosures/all_closures_skipped232=== CONT TestPartSizeForNAR233=== RUN TestPartSizeForNAR/zero_stays_at_minimum234=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum235=== RUN TestPartSizeForNAR/small_stays_at_minimum236=== PAUSE TestPartSizeForNAR/small_stays_at_minimum237=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum238=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum239=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts240=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts241=== RUN TestPartSizeForNAR/1_TiB242=== PAUSE TestPartSizeForNAR/1_TiB243=== RUN TestPartSizeForNAR/5_TiB_S3_max_object244=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object245=== RUN TestPartSizeForNAR/capped_at_5_GiB246=== PAUSE TestPartSizeForNAR/capped_at_5_GiB247=== CONT TestUploadMultipart_PartsInParallel248--- PASS: TestScriptTokenBadJSON (0.01s)249=== CONT TestShellSplitErrors250--- PASS: TestShellSplitErrors (0.00s)251=== CONT TestCaseHackSuffix252--- PASS: TestStreamPushRequestLine (0.02s)253=== CONT TestRegisterUploadedObjectReusesConnections254--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)255=== CONT TestShellSplit256--- PASS: TestShellSplit (0.00s)257=== CONT TestGetStorePathHash/valid_store_path258=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error259=== CONT TestConvertHashToNix32/SRI_format_to_Nix32260=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error261=== CONT TestConvertHashToNix32/invalid_format262=== CONT TestGetStorePathHash/basename_without_hyphen_should_error263--- PASS: TestGetStorePathHash (0.00s)264 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)265 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)266 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)267 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)268=== CONT TestConvertHashToNix32/already_Nix32_format269--- PASS: TestConvertHashToNix32 (0.00s)270 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)271 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)272 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)273=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths274=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths275--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)276 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)277 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)278=== CONT TestParsePathInfoJSON/Nix_format279=== CONT TestRateLimiterFeedback/429_enables_limiter280--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)281=== CONT TestParsePathInfoJSON/invalid_JSON282=== CONT TestParsePathInfoJSON/whitespace_only283=== CONT TestParsePathInfoJSON/empty_input284=== CONT TestParsePathInfoJSON/Lix_format285--- PASS: TestParsePathInfoJSON (0.00s)286 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)287 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)288 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)289 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)290 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)291=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)292=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512293=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295--- PASS: TestPathInfoHashCompatibility (0.00s)296 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)297 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)298 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)300=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3012026/09/20 19:22:12 WARN Rate limiter enabled after throttle name=server-test rate=53022026/09/20 19:22:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:59558303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3042026/09/20 19:22:12 WARN Rate limiter backed off name=server-test rate=5305=== CONT TestRateLimiterFeedback/503_enables_limiter306=== CONT TestPathInfoCACompatibility/null_ca_field3072026/09/20 19:22:12 WARN Rate limiter enabled after throttle name=server-test rate=53082026/09/20 19:22:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:59564309=== CONT TestPathInfoCACompatibility/new_structured_format_-_text310=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method311=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive312=== CONT TestPathInfoCACompatibility/old_string_format_-_text313--- PASS: TestPathInfoCACompatibility (0.00s)314 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)315 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)316 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)317 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)318 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)319=== CONT TestUploadMultipart_SupersededByPeer/exists3202026/09/20 19:22:12 WARN Rate limiter backed off name=server-test rate=5321--- PASS: TestRateLimiterFeedback (0.00s)322 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)326=== CONT TestUploadMultipart_SupersededByPeer/missing327=== CONT TestEncodeNixBase32/test_string_hash328=== CONT TestEncodeNixBase32/empty_input329--- PASS: TestEncodeNixBase32 (0.00s)330 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)331 --- PASS: TestEncodeNixBase32/empty_input (0.00s)332=== CONT TestSetClientTLSErrors/missing_cert_file333--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)334 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)335 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)336=== CONT TestSetClientTLSErrors/missing_ca_file337=== CONT TestSetClientTLSErrors/invalid_ca_file338=== CONT TestSetClientTLSErrors/missing_key_file339=== CONT TestSetClientTLS/rejects_connection_without_client_cert340=== CONT TestSetClientTLS/preserves_debug_logging_transport341--- PASS: TestSetClientTLSErrors (0.00s)342 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)343 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)345 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)346--- PASS: TestDumpPathWriterError (0.03s)347=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA348=== CONT TestFilterOversizedClosures/no_limit_keeps_everything349=== CONT TestFilterOversizedClosures/all_closures_skipped3502026/09/20 19:22:12 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=50351=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3522026/09/20 19:22:12 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=2000353--- PASS: TestFilterOversizedClosures (0.00s)354 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)355 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)356 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)357=== CONT TestPartSizeForNAR/zero_stays_at_minimum358=== CONT TestPartSizeForNAR/capped_at_5_GiB359=== CONT TestPartSizeForNAR/5_TiB_S3_max_object360=== CONT TestPartSizeForNAR/1_TiB361=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts362=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum363=== CONT TestPartSizeForNAR/small_stays_at_minimum364--- PASS: TestPartSizeForNAR (0.00s)365 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)367 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)368 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)369 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)370 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)372--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)3732026/09/20 19:22:12 http: TLS handshake error from 127.0.0.1:59570: 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.07s)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-84476-2894457087/postgres541372010/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-84476-2894457087/postgres541372010/data -l logfile start412413/nix/var/nix/builds/nix-84476-2894457087/postgres541372010:5432 - no response4142026-09-20 19:22:13.705 UTC [84555] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4152026-09-20 19:22:13.706 UTC [84555] LOG: listening on Unix socket "/nix/var/nix/builds/nix-84476-2894457087/postgres541372010/.s.PGSQL.5432"4162026-09-20 19:22:13.708 UTC [84562] LOG: database system was shut down at 2026-09-20 19:22:13 UTC4172026-09-20 19:22:13.709 UTC [84555] LOG: database system is ready to accept connections418/nix/var/nix/builds/nix-84476-2894457087/postgres541372010: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 TestLeadEndsOnShutdown456=== PAUSE TestLeadEndsOnShutdown457=== RUN TestGCAdvisoryLockBlocksConcurrentRun4582026-09-20 19:22:13.988 UTC [84571] ERROR: relation "goose_db_version" does not exist at character 364592026-09-20 19:22:13.988 UTC [84571] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4602026/09/20 19:22:13 OK 20241026095416_initial_model.sql (4.06ms)4612026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (52.52ms)4622026/09/20 19:22:14 OK 20251218171726_add_pins.sql (8.61ms)4632026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (855.63µs)4642026/09/20 19:22:14 OK 20260905000000_add_claims.sql (897.42µs)4652026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (537.79µs)4662026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000004672026/09/20 19:22:14 OK 1_commit_pending_closure.sql (801.08µs)4682026/09/20 19:22:14 OK 2_object_stats_trigger.sql (181.17µs)4692026/09/20 19:22:14 goose: up to current file version: 2470--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.43s)471=== RUN TestGCBugBareHashReferences472=== PAUSE TestGCBugBareHashReferences473=== RUN TestGCMetrics474=== PAUSE TestGCMetrics475=== RUN TestGCTaskStore_StartNew476=== PAUSE TestGCTaskStore_StartNew477=== RUN TestGCTaskStore_DeduplicateSameParams478=== PAUSE TestGCTaskStore_DeduplicateSameParams479=== RUN TestGCTaskStore_ConflictDifferentParams480=== PAUSE TestGCTaskStore_ConflictDifferentParams481=== RUN TestGCTaskStore_GetEmpty482=== PAUSE TestGCTaskStore_GetEmpty483=== RUN TestGCTaskStore_GetReturnsLatest484=== PAUSE TestGCTaskStore_GetReturnsLatest485=== RUN TestGCTaskStore_CompletedAllowsNewTask486=== PAUSE TestGCTaskStore_CompletedAllowsNewTask487=== RUN TestGCTaskStore_PhaseUpdates488=== PAUSE TestGCTaskStore_PhaseUpdates489=== RUN TestGCTaskStore_Fail490=== PAUSE TestGCTaskStore_Fail491=== RUN TestGracefulShutdownDrainsInflight492=== PAUSE TestGracefulShutdownDrainsInflight493=== RUN TestService_healthCheckHandler494=== PAUSE TestService_healthCheckHandler495=== RUN TestService_readinessHandler496=== PAUSE TestService_readinessHandler497=== RUN TestGenerateLandingPage498=== PAUSE TestGenerateLandingPage499=== RUN TestCacheConfigHandlerMaxNarSize500=== PAUSE TestCacheConfigHandlerMaxNarSize501=== RUN TestCreatePendingClosureRejectsOversizedNAR502=== PAUSE TestCreatePendingClosureRejectsOversizedNAR503=== RUN TestNARDeduplicationMetadataUploadBug504=== PAUSE TestNARDeduplicationMetadataUploadBug505=== RUN TestMetricsInventory506=== PAUSE TestMetricsInventory507=== RUN TestService_NativeMTLS508=== PAUSE TestService_NativeMTLS509=== RUN TestServerTLSConfig510=== PAUSE TestServerTLSConfig511=== RUN TestMultipartCleanup512=== PAUSE TestMultipartCleanup513=== RUN TestObjectStatsTrigger514=== PAUSE TestObjectStatsTrigger515=== RUN TestOrphanedObjectsGC516=== PAUSE TestOrphanedObjectsGC517=== RUN TestOrphanedObjectsGCStressTest518=== PAUSE TestOrphanedObjectsGCStressTest519=== RUN TestResurrectedObjectNotDeleted520=== PAUSE TestResurrectedObjectNotDeleted521=== RUN TestParseSingleRange522=== PAUSE TestParseSingleRange523=== RUN TestIsValidCachePath524=== PAUSE TestIsValidCachePath525=== RUN TestReadProxyNarinfo526=== PAUSE TestReadProxyNarinfo527=== RUN TestReadProxyNarinfoAlreadyDecompressed528=== PAUSE TestReadProxyNarinfoAlreadyDecompressed529=== RUN TestReadProxyNarStreaming530=== PAUSE TestReadProxyNarStreaming531=== RUN TestReadProxy404532=== PAUSE TestReadProxy404533=== RUN TestReadProxyInvalidPath534=== PAUSE TestReadProxyInvalidPath535=== RUN TestReadProxyHead536=== PAUSE TestReadProxyHead537=== RUN TestReadProxyConditionalGet538=== PAUSE TestReadProxyConditionalGet539=== RUN TestReadProxyRootRedirectsToIndexHTML540=== PAUSE TestReadProxyRootRedirectsToIndexHTML541=== RUN TestReadProxyDisabled542=== PAUSE TestReadProxyDisabled543=== RUN TestReadRedirectNar544=== PAUSE TestReadRedirectNar545=== RUN TestReadRedirectKeepsNarinfoProxied546=== PAUSE TestReadRedirectKeepsNarinfoProxied547=== RUN TestReadProxyRangeRequest548=== PAUSE TestReadProxyRangeRequest549=== RUN TestReadRedirectUsesPublicS3URL550=== PAUSE TestReadRedirectUsesPublicS3URL551=== RUN TestRedundantMultipartUpload552=== PAUSE TestRedundantMultipartUpload553=== RUN TestCompleteMultipartUpload_ErrorButObjectExists554=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists555=== RUN TestCompletedNarNotReofferedAcrossClosures556=== PAUSE TestCompletedNarNotReofferedAcrossClosures557=== RUN TestPresignedUploadRegisteredBeforeCommit558=== PAUSE TestPresignedUploadRegisteredBeforeCommit559=== RUN TestService_Rustfstest560=== PAUSE TestService_Rustfstest561=== RUN TestParseSize562=== PAUSE TestParseSize563=== RUN TestSkippedUploadsHandler564=== PAUSE TestSkippedUploadsHandler565=== RUN TestSystemdListenerNotActivated566--- PASS: TestSystemdListenerNotActivated (0.00s)567=== RUN TestWatchdogBeatsWhenHealthy568--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)569=== RUN TestWatchdogSkipsWhenUnhealthy5702026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/20 19:22:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"580--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)581=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle582=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle583=== RUN TestProxyWriteTimeout584=== PAUSE TestProxyWriteTimeout585=== RUN TestIsValidUploadKey586=== PAUSE TestIsValidUploadKey587=== RUN TestUploadHandlersRejectInvalidKeys588=== PAUSE TestUploadHandlersRejectInvalidKeys589=== RUN TestUploadHandlersRejectOversizedBody590=== PAUSE TestUploadHandlersRejectOversizedBody591=== RUN TestService_cleanupPendingClosuresHandler592=== PAUSE TestService_cleanupPendingClosuresHandler593=== RUN TestService_createPendingClosureHandler594=== PAUSE TestService_createPendingClosureHandler595=== RUN TestService_verifyS3Integrity596=== PAUSE TestService_verifyS3Integrity597=== RUN TestCompleteMultipartUnregistered598=== PAUSE TestCompleteMultipartUnregistered599=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT600=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT601=== CONT TestReadRedirectUsesPublicS3URL602=== CONT TestReadRedirectNar603=== CONT TestProxyWriteTimeout604=== RUN TestProxyWriteTimeout/narinfo605=== PAUSE TestProxyWriteTimeout/narinfo606=== RUN TestProxyWriteTimeout/1_GiB_nar607=== PAUSE TestProxyWriteTimeout/1_GiB_nar608=== CONT TestClientSharedPathCommittedMidPush609=== CONT TestService_AuthMiddleware610=== RUN TestProxyWriteTimeout/10_GiB_nar611=== PAUSE TestProxyWriteTimeout/10_GiB_nar612=== RUN TestProxyWriteTimeout/unknown_size613=== PAUSE TestProxyWriteTimeout/unknown_size614=== CONT TestReadProxyRangeRequest615=== CONT TestReadRedirectKeepsNarinfoProxied616=== CONT TestService_verifyS3Integrity617=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT618=== CONT TestCompleteMultipartUnregistered619=== CONT TestGCTaskStore_Fail620--- PASS: TestGCTaskStore_Fail (0.00s)621=== CONT TestService_createPendingClosureHandler6222026-09-20 19:22:14.896 UTC [84660] ERROR: relation "goose_db_version" does not exist at character 366232026-09-20 19:22:14.896 UTC [84660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6242026-09-20 19:22:14.896 UTC [84662] ERROR: relation "goose_db_version" does not exist at character 366252026-09-20 19:22:14.896 UTC [84662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6262026-09-20 19:22:14.896 UTC [84661] ERROR: relation "goose_db_version" does not exist at character 366272026-09-20 19:22:14.896 UTC [84661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6282026-09-20 19:22:14.909 UTC [84663] ERROR: relation "goose_db_version" does not exist at character 366292026-09-20 19:22:14.909 UTC [84663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6302026-09-20 19:22:14.909 UTC [84664] ERROR: relation "goose_db_version" does not exist at character 366312026-09-20 19:22:14.909 UTC [84664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6322026-09-20 19:22:14.909 UTC [84665] ERROR: relation "goose_db_version" does not exist at character 366332026-09-20 19:22:14.909 UTC [84665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6342026-09-20 19:22:14.912 UTC [84667] ERROR: relation "goose_db_version" does not exist at character 366352026-09-20 19:22:14.912 UTC [84667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6362026-09-20 19:22:14.913 UTC [84666] ERROR: relation "goose_db_version" does not exist at character 366372026-09-20 19:22:14.913 UTC [84666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026-09-20 19:22:14.913 UTC [84668] ERROR: relation "goose_db_version" does not exist at character 366392026-09-20 19:22:14.913 UTC [84668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6402026/09/20 19:22:14 OK 20241026095416_initial_model.sql (11.41ms)6412026/09/20 19:22:14 OK 20241026095416_initial_model.sql (11.28ms)6422026-09-20 19:22:14.914 UTC [84669] ERROR: relation "goose_db_version" does not exist at character 366432026-09-20 19:22:14.914 UTC [84669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (729.83µs)6452026/09/20 19:22:14 OK 20241026095416_initial_model.sql (12.42ms)6462026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (601.13µs)6472026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (753.46µs)6482026/09/20 19:22:14 OK 20251218171726_add_pins.sql (2.21ms)6492026/09/20 19:22:14 OK 20251218171726_add_pins.sql (2.33ms)6502026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.87ms)6512026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.57ms)6522026/09/20 19:22:14 OK 20241026095416_initial_model.sql (6.95ms)6532026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (2.55ms)6542026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)6552026/09/20 19:22:14 OK 20241026095416_initial_model.sql (7.51ms)6562026/09/20 19:22:14 OK 20260905000000_add_claims.sql (1.94ms)6572026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)6582026/09/20 19:22:14 OK 20241026095416_initial_model.sql (7.42ms)6592026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (893.83µs)6602026/09/20 19:22:14 OK 20260905000000_add_claims.sql (2.13ms)6612026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (1.35ms)6622026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000006632026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.37ms)6642026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (765.83µs)6652026/09/20 19:22:14 OK 20260905000000_add_claims.sql (2.71ms)6662026/09/20 19:22:14 OK 20241026095416_initial_model.sql (6.14ms)6672026/09/20 19:22:14 OK 1_commit_pending_closure.sql (1.06ms)6682026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (1.25ms)6692026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000006702026/09/20 19:22:14 OK 2_object_stats_trigger.sql (320.92µs)6712026/09/20 19:22:14 goose: up to current file version: 26722026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.65ms)6732026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (685.13µs)6742026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.59ms)6752026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (1.34ms)6762026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000006772026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.85ms)6782026/09/20 19:22:14 OK 20241026095416_initial_model.sql (8.14ms)6792026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.21ms)6802026/09/20 19:22:14 OK 20241026095416_initial_model.sql (7.16ms)6812026/09/20 19:22:14 OK 1_commit_pending_closure.sql (1.7ms)6822026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.46ms)6832026/09/20 19:22:14 OK 1_commit_pending_closure.sql (964.71µs)6842026/09/20 19:22:14 OK 2_object_stats_trigger.sql (385.71µs)6852026/09/20 19:22:14 goose: up to current file version: 26862026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (489.79µs)6872026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (448.75µs)6882026/09/20 19:22:14 OK 20241026095416_initial_model.sql (7.96ms)6892026/09/20 19:22:14 OK 2_object_stats_trigger.sql (379.46µs)6902026/09/20 19:22:14 goose: up to current file version: 26912026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.38ms)6922026/09/20 19:22:14 OK 20260905000000_add_claims.sql (2.3ms)6932026/09/20 19:22:14 OK 20251210153512_drop_unused_gin_index.sql (730.54µs)6942026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.27ms)6952026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.37ms)6962026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.48ms)6972026/09/20 19:22:14 OK 20260905000000_add_claims.sql (1.09ms)6982026/09/20 19:22:14 OK 20260905000000_add_claims.sql (2.33ms)6992026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (1.33ms)7002026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007012026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (955.33µs)7022026/09/20 19:22:14 OK 20251218171726_add_pins.sql (1.79ms)7032026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)7042026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (938.33µs)7052026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007062026/09/20 19:22:14 OK 20260905000000_add_claims.sql (1.6ms)7072026/09/20 19:22:14 OK 1_commit_pending_closure.sql (831.71µs)7082026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (1.28ms)7092026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007102026/09/20 19:22:14 OK 2_object_stats_trigger.sql (395µs)7112026/09/20 19:22:14 goose: up to current file version: 27122026/09/20 19:22:14 OK 20260628120000_add_object_size_and_stats.sql (1.09ms)7132026/09/20 19:22:14 OK 1_commit_pending_closure.sql (1.07ms)7142026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (875.04µs)7152026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007162026/09/20 19:22:14 OK 1_commit_pending_closure.sql (807.92µs)7172026/09/20 19:22:14 OK 20260905000000_add_claims.sql (1.88ms)7182026/09/20 19:22:14 OK 2_object_stats_trigger.sql (276.79µs)7192026/09/20 19:22:14 goose: up to current file version: 27202026/09/20 19:22:14 OK 2_object_stats_trigger.sql (295.08µs)7212026/09/20 19:22:14 goose: up to current file version: 27222026/09/20 19:22:14 OK 20260905000000_add_claims.sql (1.67ms)7232026/09/20 19:22:14 OK 20260905000000_add_claims.sql (947.5µs)7242026/09/20 19:22:14 OK 1_commit_pending_closure.sql (953.58µs)7252026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (773.88µs)7262026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007272026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (626.63µs)7282026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007292026/09/20 19:22:14 OK 2_object_stats_trigger.sql (222.08µs)7302026/09/20 19:22:14 goose: up to current file version: 27312026/09/20 19:22:14 OK 20260920000000_drop_claims.sql (611.79µs)7322026/09/20 19:22:14 goose: successfully migrated database to version: 202609200000007332026/09/20 19:22:14 OK 1_commit_pending_closure.sql (733.04µs)7342026/09/20 19:22:14 OK 1_commit_pending_closure.sql (660.33µs)7352026/09/20 19:22:14 OK 2_object_stats_trigger.sql (183.83µs)7362026/09/20 19:22:14 goose: up to current file version: 27372026/09/20 19:22:14 OK 2_object_stats_trigger.sql (195.42µs)7382026/09/20 19:22:14 goose: up to current file version: 27392026/09/20 19:22:14 OK 1_commit_pending_closure.sql (649.92µs)7402026/09/20 19:22:14 OK 2_object_stats_trigger.sql (177.58µs)7412026/09/20 19:22:14 goose: up to current file version: 2742--- PASS: TestReadRedirectKeepsNarinfoProxied (0.44s)743=== CONT TestService_cleanupPendingClosuresHandler7442026/09/20 19:22:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"745--- PASS: TestService_AuthMiddleware (0.53s)746=== CONT TestUploadHandlersRejectOversizedBody747=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure748=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure749=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart750=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart751=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts752=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts753=== CONT TestUploadHandlersRejectInvalidKeys754=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info755=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info756=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal757=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal758=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key759=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key760=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key761=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key762=== CONT TestIsValidUploadKey763=== RUN TestIsValidUploadKey/narinfo764=== PAUSE TestIsValidUploadKey/narinfo765=== RUN TestIsValidUploadKey/nar_zst766=== PAUSE TestIsValidUploadKey/nar_zst767=== RUN TestIsValidUploadKey/nar_xz768=== PAUSE TestIsValidUploadKey/nar_xz769=== RUN TestIsValidUploadKey/nar_plain770=== PAUSE TestIsValidUploadKey/nar_plain771=== RUN TestIsValidUploadKey/listing772=== PAUSE TestIsValidUploadKey/listing773=== RUN TestIsValidUploadKey/build_log774=== PAUSE TestIsValidUploadKey/build_log775=== RUN TestIsValidUploadKey/build_log_home-manager_file776=== PAUSE TestIsValidUploadKey/build_log_home-manager_file777=== RUN TestIsValidUploadKey/build_log_plus_in_name778=== PAUSE TestIsValidUploadKey/build_log_plus_in_name779=== RUN TestIsValidUploadKey/build_log_question_mark780=== PAUSE TestIsValidUploadKey/build_log_question_mark781=== RUN TestIsValidUploadKey/build_log_equals782=== PAUSE TestIsValidUploadKey/build_log_equals783=== RUN TestIsValidUploadKey/realisation784=== PAUSE TestIsValidUploadKey/realisation785=== RUN TestIsValidUploadKey/realisation_plus_in_output786=== PAUSE TestIsValidUploadKey/realisation_plus_in_output787=== RUN TestIsValidUploadKey/nix-cache-info788=== PAUSE TestIsValidUploadKey/nix-cache-info789=== RUN TestIsValidUploadKey/index.html790=== PAUSE TestIsValidUploadKey/index.html791=== RUN TestIsValidUploadKey/narinfo_key,_nar_type792=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type793=== RUN TestIsValidUploadKey/nar_key,_narinfo_type794=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type795=== RUN TestIsValidUploadKey/listing_key,_narinfo_type796=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type797=== RUN TestIsValidUploadKey/traversal798=== PAUSE TestIsValidUploadKey/traversal799=== RUN TestIsValidUploadKey/traversal_nar800=== PAUSE TestIsValidUploadKey/traversal_nar801=== RUN TestIsValidUploadKey/absolute802=== PAUSE TestIsValidUploadKey/absolute803=== RUN TestIsValidUploadKey/empty_key804=== PAUSE TestIsValidUploadKey/empty_key805=== RUN TestIsValidUploadKey/unknown_type806=== PAUSE TestIsValidUploadKey/unknown_type807=== CONT TestGCTaskStore_StartNew808--- PASS: TestGCTaskStore_StartNew (0.00s)809=== CONT TestGCTaskStore_PhaseUpdates810--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)811=== CONT TestGCTaskStore_CompletedAllowsNewTask812--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)813=== CONT TestGCTaskStore_GetReturnsLatest814--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)815=== CONT TestGCTaskStore_GetEmpty816--- PASS: TestGCTaskStore_GetEmpty (0.00s)817=== CONT TestGCTaskStore_ConflictDifferentParams818--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)819=== CONT TestGCTaskStore_DeduplicateSameParams820--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)821=== CONT TestService_Rustfstest822--- PASS: TestReadRedirectNar (0.66s)823=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8242026/09/20 19:22:15 INFO Received uploads request method=POST path=/api/pending_closures8252026/09/20 19:22:15 INFO Received uploads request method=POST path=/api/pending_closures8262026/09/20 19:22:15 INFO Received uploads request method=POST path=/api/pending_closures8272026/09/20 19:22:15 INFO Received uploads request method=POST path=/api/pending_closures828--- PASS: TestReadRedirectUsesPublicS3URL (1.20s)829=== CONT TestSkippedUploadsHandler8302026/09/20 19:22:15 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000831--- PASS: TestSkippedUploadsHandler (0.00s)832=== CONT TestParseSize833--- PASS: TestParseSize (0.00s)834=== CONT TestReadProxyDisabled8352026-09-20 19:22:15.809 UTC [84676] ERROR: relation "goose_db_version" does not exist at character 368362026-09-20 19:22:15.809 UTC [84676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026-09-20 19:22:15.907 UTC [84679] ERROR: relation "goose_db_version" does not exist at character 368382026-09-20 19:22:15.907 UTC [84679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026/09/20 19:22:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8402026/09/20 19:22:15 OK 20241026095416_initial_model.sql (144.57ms)8412026/09/20 19:22:15 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst842--- PASS: TestCompleteMultipartUnregistered (1.39s)843=== CONT TestReadProxyRootRedirectsToIndexHTML8442026/09/20 19:22:15 OK 20251210153512_drop_unused_gin_index.sql (11.52ms)8452026/09/20 19:22:16 OK 20251218171726_add_pins.sql (24.2ms)8462026/09/20 19:22:16 OK 20260628120000_add_object_size_and_stats.sql (20.05ms)8472026/09/20 19:22:16 OK 20241026095416_initial_model.sql (137.42ms)8482026/09/20 19:22:16 OK 20251210153512_drop_unused_gin_index.sql (10.32ms)8492026/09/20 19:22:16 OK 20260905000000_add_claims.sql (68.62ms)8502026-09-20 19:22:16.110 UTC [84682] ERROR: relation "goose_db_version" does not exist at character 368512026-09-20 19:22:16.110 UTC [84682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8522026/09/20 19:22:16 OK 20251218171726_add_pins.sql (22.34ms)8532026/09/20 19:22:16 OK 20260920000000_drop_claims.sql (20.95ms)8542026/09/20 19:22:16 goose: successfully migrated database to version: 202609200000008552026/09/20 19:22:16 OK 1_commit_pending_closure.sql (1.61ms)8562026/09/20 19:22:16 OK 2_object_stats_trigger.sql (363.67µs)8572026/09/20 19:22:16 goose: up to current file version: 28582026/09/20 19:22:16 OK 20260628120000_add_object_size_and_stats.sql (19.66ms)8592026/09/20 19:22:16 OK 20260905000000_add_claims.sql (33.47ms)8602026/09/20 19:22:16 OK 20260920000000_drop_claims.sql (28.04ms)8612026/09/20 19:22:16 goose: successfully migrated database to version: 202609200000008622026/09/20 19:22:16 OK 1_commit_pending_closure.sql (1.73ms)8632026/09/20 19:22:16 OK 2_object_stats_trigger.sql (402µs)8642026/09/20 19:22:16 goose: up to current file version: 28652026/09/20 19:22:16 OK 20241026095416_initial_model.sql (114.58ms)8662026/09/20 19:22:16 OK 20251210153512_drop_unused_gin_index.sql (9.97ms)8672026/09/20 19:22:16 OK 20251218171726_add_pins.sql (24.01ms)8682026/09/20 19:22:16 OK 20260628120000_add_object_size_and_stats.sql (31.6ms)8692026/09/20 19:22:16 OK 20260905000000_add_claims.sql (22.21ms)8702026/09/20 19:22:16 OK 20260920000000_drop_claims.sql (20.42ms)8712026/09/20 19:22:16 goose: successfully migrated database to version: 202609200000008722026/09/20 19:22:16 OK 1_commit_pending_closure.sql (1.22ms)8732026/09/20 19:22:16 OK 2_object_stats_trigger.sql (279.75µs)8742026/09/20 19:22:16 goose: up to current file version: 2875--- PASS: TestReadProxyRangeRequest (1.84s)876=== CONT TestReadProxyConditionalGet8772026/09/20 19:22:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8782026/09/20 19:22:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8792026/09/20 19:22:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWNiM2MwMzYtNWQzNy00ODY3LWJiYTgtMTY0ZjJkYWQ0YzIxLmY0YjhjMzE0LWE2ZDctNDgzMi1iMjc1LWRmYzYwZTU3NTkwOXgxNzg5OTMyMTM1NDA0NDU3MDAw parts=108802026/09/20 19:22:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026/09/20 19:22:16 INFO Completed upload id=18822026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures8832026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures8842026/09/20 19:22:16 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8852026/09/20 19:22:16 WARN Found objects in DB but missing from S3, will re-upload count=1886--- PASS: TestService_verifyS3Integrity (1.98s)887=== CONT TestReadProxyHead8882026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures8892026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures8902026/09/20 19:22:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8912026/09/20 19:22:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWNiM2MwMzYtNWQzNy00ODY3LWJiYTgtMTY0ZjJkYWQ0YzIxLjI0MWE3YTc2LWZhYzMtNDU5MS1hOWQzLTM2NGEwNDlkYjQ0YXgxNzg5OTMyMTM1NTUxNDc2MDAw parts=108922026/09/20 19:22:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8932026/09/20 19:22:16 INFO Completed upload id=18942026/09/20 19:22:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008952026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures8962026/09/20 19:22:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures8972026/09/20 19:22:16 INFO Aborted multipart uploads count=08982026/09/20 19:22:16 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=08992026/09/20 19:22:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"900--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.11s)901=== CONT TestReadProxyInvalidPath9022026/09/20 19:22:16 INFO Vacuumed table table=pending_closures9032026/09/20 19:22:16 INFO Vacuumed table table=pending_objects9042026/09/20 19:22:16 INFO Vacuumed table table=multipart_uploads9052026-09-20 19:22:16.722 UTC [84705] ERROR: relation "goose_db_version" does not exist at character 369062026-09-20 19:22:16.722 UTC [84705] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026/09/20 19:22:16 INFO Vacuumed table table=closures9082026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures9092026/09/20 19:22:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9102026/09/20 19:22:16 INFO Uploading lacbhyc2j41rdld34f6kdx8rcpclphyr-shared-dep (136B)9112026/09/20 19:22:16 INFO Vacuumed table table=objects9122026/09/20 19:22:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9132026/09/20 19:22:16 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000914--- PASS: TestService_createPendingClosureHandler (2.15s)915=== CONT TestReadProxy4049162026/09/20 19:22:16 WARN Failed to register uploaded object key=lacbhyc2j41rdld34f6kdx8rcpclphyr.ls error="server returned 404: 404 page not found\n"9172026/09/20 19:22:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9182026/09/20 19:22:16 INFO Signed narinfos id=2 count=19192026/09/20 19:22:16 INFO Uploading 1 narinfos9202026/09/20 19:22:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9212026/09/20 19:22:16 WARN Failed to register uploaded object key=lacbhyc2j41rdld34f6kdx8rcpclphyr.narinfo error="server returned 404: 404 page not found\n"9222026/09/20 19:22:16 INFO Completed upload id=29232026/09/20 19:22:16 INFO Upload complete. (125ms)9242026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures9252026/09/20 19:22:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9262026/09/20 19:22:16 INFO Uploading lacbhyc2j41rdld34f6kdx8rcpclphyr-shared-dep (136B)9272026/09/20 19:22:16 INFO Uploading 8pxzql5j2q42gb4c62dn1jrq77mqxwzb-top (256B)9282026/09/20 19:22:16 WARN Failed to register uploaded object key=nar/02hb6cyap3cw65z8jlx3jla0fgx2k7biy2cv3ydf87yinxj7wwi6.nar.zst error="server returned 404: 404 page not found\n"9292026/09/20 19:22:16 WARN Failed to register uploaded object key=8pxzql5j2q42gb4c62dn1jrq77mqxwzb.ls error="server returned 404: 404 page not found\n"9302026/09/20 19:22:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9312026/09/20 19:22:16 INFO Received cleanup request method=DELETE path=/api/pending_closures9322026/09/20 19:22:16 INFO Aborted multipart uploads count=09332026/09/20 19:22:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9342026/09/20 19:22:16 WARN Failed to register uploaded object key=lacbhyc2j41rdld34f6kdx8rcpclphyr.ls error="server returned 404: 404 page not found\n"9352026/09/20 19:22:16 INFO Signed narinfos id=1 count=19362026/09/20 19:22:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign9372026/09/20 19:22:16 INFO Signed narinfos id=3 count=19382026/09/20 19:22:16 INFO Uploading 2 narinfos9392026/09/20 19:22:16 INFO Received uploads request method=POST path=/api/pending_closures9402026/09/20 19:22:16 WARN Failed to register uploaded object key=8pxzql5j2q42gb4c62dn1jrq77mqxwzb.narinfo error="server returned 404: 404 page not found\n"9412026/09/20 19:22:16 OK 20241026095416_initial_model.sql (60.99ms)9422026/09/20 19:22:16 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)9432026/09/20 19:22:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9442026/09/20 19:22:16 WARN Failed to register uploaded object key=lacbhyc2j41rdld34f6kdx8rcpclphyr.narinfo error="server returned 404: 404 page not found\n"9452026/09/20 19:22:16 INFO Completed upload id=19462026/09/20 19:22:16 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete9472026/09/20 19:22:16 INFO Completed upload id=39482026/09/20 19:22:16 INFO Upload complete. (328ms)949=== NAME TestClientSharedPathCommittedMidPush950 client_integration_test.go:680: Retrieved narinfo from S3:951 StorePath: /nix/var/nix/builds/nix-84476-2894457087/TestClientSharedPathCommittedMidPush2089125037/001/store/lacbhyc2j41rdld34f6kdx8rcpclphyr-shared-dep952 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst953 Compression: zstd954 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82955 NarSize: 136956 References: 957 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n958 client_integration_test.go:680: Retrieved narinfo from S3:959 StorePath: /nix/var/nix/builds/nix-84476-2894457087/TestClientSharedPathCommittedMidPush2089125037/001/store/8pxzql5j2q42gb4c62dn1jrq77mqxwzb-top960 URL: nar/02hb6cyap3cw65z8jlx3jla0fgx2k7biy2cv3ydf87yinxj7wwi6.nar.zst961 Compression: zstd962 NarHash: sha256:02hb6cyap3cw65z8jlx3jla0fgx2k7biy2cv3ydf87yinxj7wwi6963 NarSize: 256964 References: /nix/var/nix/builds/nix-84476-2894457087/TestClientSharedPathCommittedMidPush2089125037/001/store/lacbhyc2j41rdld34f6kdx8rcpclphyr-shared-dep965 CA: text:sha256:19qgd40w42wvcy517axdpdx25rm63pdwzqxnvxj1pdp9hq5plc699662026/09/20 19:22:16 OK 20251218171726_add_pins.sql (24.85ms)9672026/09/20 19:22:16 INFO Received cleanup request method=DELETE path=/api/pending_closures968--- PASS: TestClientSharedPathCommittedMidPush (2.26s)969=== CONT TestReadProxyNarStreaming9702026/09/20 19:22:16 INFO Aborted multipart uploads count=19712026/09/20 19:22:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9722026-09-20 19:22:16.848 UTC [84676] ERROR: Closure does not exist: id=19732026-09-20 19:22:16.848 UTC [84676] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9742026-09-20 19:22:16.848 UTC [84676] STATEMENT: -- name: CommitPendingClosure :exec975 SELECT commit_pending_closure($1::bigint)976 977--- PASS: TestService_cleanupPendingClosuresHandler (1.82s)978=== CONT TestReadProxyNarinfoAlreadyDecompressed9792026/09/20 19:22:16 OK 20260628120000_add_object_size_and_stats.sql (14.63ms)9802026-09-20 19:22:16.855 UTC [84710] ERROR: relation "goose_db_version" does not exist at character 369812026-09-20 19:22:16.855 UTC [84710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9822026/09/20 19:22:16 OK 20260905000000_add_claims.sql (14.92ms)9832026/09/20 19:22:16 OK 20260920000000_drop_claims.sql (15.13ms)9842026/09/20 19:22:16 goose: successfully migrated database to version: 202609200000009852026/09/20 19:22:16 OK 1_commit_pending_closure.sql (1.19ms)9862026/09/20 19:22:16 OK 2_object_stats_trigger.sql (243.21µs)9872026/09/20 19:22:16 goose: up to current file version: 2988--- PASS: TestService_Rustfstest (1.80s)989=== CONT TestReadProxyNarinfo9902026/09/20 19:22:16 OK 20241026095416_initial_model.sql (66.39ms)9912026/09/20 19:22:16 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)9922026/09/20 19:22:16 OK 20251218171726_add_pins.sql (14.09ms)9932026/09/20 19:22:16 OK 20260628120000_add_object_size_and_stats.sql (11.83ms)9942026/09/20 19:22:16 OK 20260905000000_add_claims.sql (24.77ms)9952026/09/20 19:22:16 OK 20260920000000_drop_claims.sql (2.12ms)9962026/09/20 19:22:16 goose: successfully migrated database to version: 202609200000009972026/09/20 19:22:17 OK 1_commit_pending_closure.sql (1.63ms)9982026/09/20 19:22:17 OK 2_object_stats_trigger.sql (244.83µs)9992026/09/20 19:22:17 goose: up to current file version: 210002026/09/20 19:22:17 INFO Received uploads request method=POST path=/api/pending_closures1001--- PASS: TestReadProxyDisabled (1.46s)1002=== CONT TestIsValidCachePath1003=== RUN TestIsValidCachePath/narinfo1004=== PAUSE TestIsValidCachePath/narinfo1005=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1006=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1007=== RUN TestIsValidCachePath/nar_zst1008=== PAUSE TestIsValidCachePath/nar_zst1009=== RUN TestIsValidCachePath/nar_xz1010=== PAUSE TestIsValidCachePath/nar_xz1011=== RUN TestIsValidCachePath/nar_bz21012=== PAUSE TestIsValidCachePath/nar_bz21013=== RUN TestIsValidCachePath/nar_uncompressed1014=== PAUSE TestIsValidCachePath/nar_uncompressed1015=== RUN TestIsValidCachePath/ls1016=== PAUSE TestIsValidCachePath/ls1017=== RUN TestIsValidCachePath/log1018=== PAUSE TestIsValidCachePath/log1019=== RUN TestIsValidCachePath/realisation1020=== PAUSE TestIsValidCachePath/realisation1021=== RUN TestIsValidCachePath/nix-cache-info1022=== PAUSE TestIsValidCachePath/nix-cache-info1023=== RUN TestIsValidCachePath/index.html1024=== PAUSE TestIsValidCachePath/index.html1025=== RUN TestIsValidCachePath/traversal_parent1026=== PAUSE TestIsValidCachePath/traversal_parent1027=== RUN TestIsValidCachePath/traversal_in_middle1028=== PAUSE TestIsValidCachePath/traversal_in_middle1029=== RUN TestIsValidCachePath/invalid_char_e1030=== PAUSE TestIsValidCachePath/invalid_char_e1031=== RUN TestIsValidCachePath/invalid_char_u1032=== PAUSE TestIsValidCachePath/invalid_char_u1033=== RUN TestIsValidCachePath/random_path1034=== PAUSE TestIsValidCachePath/random_path1035=== RUN TestIsValidCachePath/empty1036=== PAUSE TestIsValidCachePath/empty1037=== RUN TestIsValidCachePath/leading_slash1038=== PAUSE TestIsValidCachePath/leading_slash1039=== RUN TestIsValidCachePath/wrong_extension1040=== PAUSE TestIsValidCachePath/wrong_extension1041=== RUN TestIsValidCachePath/short_hash1042=== PAUSE TestIsValidCachePath/short_hash1043=== CONT TestCacheConfigHandler1044=== RUN TestCacheConfigHandler/full_config,_no_issuer1045=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1046=== RUN TestCacheConfigHandler/no_cache_url_configured1047=== PAUSE TestCacheConfigHandler/no_cache_url_configured1048=== RUN TestCacheConfigHandler/no_signing_keys1049=== PAUSE TestCacheConfigHandler/no_signing_keys1050=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1051=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1052=== CONT TestClientWithDependencies10532026/09/20 19:22:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1054--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.51s)1055=== CONT TestParseSingleRange1056=== RUN TestParseSingleRange/none1057=== PAUSE TestParseSingleRange/none1058=== RUN TestParseSingleRange/unknown_unit1059=== PAUSE TestParseSingleRange/unknown_unit1060=== RUN TestParseSingleRange/multi-range_ignored1061=== PAUSE TestParseSingleRange/multi-range_ignored1062=== RUN TestParseSingleRange/malformed_no_dash1063=== PAUSE TestParseSingleRange/malformed_no_dash1064=== RUN TestParseSingleRange/malformed_both_empty1065=== PAUSE TestParseSingleRange/malformed_both_empty1066=== RUN TestParseSingleRange/malformed_end_before_start1067=== PAUSE TestParseSingleRange/malformed_end_before_start1068=== RUN TestParseSingleRange/closed1069=== PAUSE TestParseSingleRange/closed1070=== RUN TestParseSingleRange/open-ended1071=== PAUSE TestParseSingleRange/open-ended1072=== RUN TestParseSingleRange/end_clamped_to_size1073=== PAUSE TestParseSingleRange/end_clamped_to_size1074=== RUN TestParseSingleRange/suffix1075=== PAUSE TestParseSingleRange/suffix1076=== RUN TestParseSingleRange/suffix_exceeds_size1077=== PAUSE TestParseSingleRange/suffix_exceeds_size1078=== RUN TestParseSingleRange/single_byte1079=== PAUSE TestParseSingleRange/single_byte1080=== RUN TestParseSingleRange/start_past_EOF1081=== PAUSE TestParseSingleRange/start_past_EOF1082=== RUN TestParseSingleRange/start_far_past_EOF1083=== PAUSE TestParseSingleRange/start_far_past_EOF1084=== CONT TestClientMultipleUploads10852026-09-20 19:22:17.507 UTC [84719] ERROR: relation "goose_db_version" does not exist at character 3610862026-09-20 19:22:17.507 UTC [84719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026-09-20 19:22:17.508 UTC [84720] ERROR: relation "goose_db_version" does not exist at character 3610882026-09-20 19:22:17.508 UTC [84720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10892026-09-20 19:22:17.520 UTC [84722] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-20 19:22:17.520 UTC [84722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026/09/20 19:22:17 OK 20241026095416_initial_model.sql (10.58ms)10922026/09/20 19:22:17 OK 20251210153512_drop_unused_gin_index.sql (500.58µs)10932026/09/20 19:22:17 OK 20241026095416_initial_model.sql (11.12ms)10942026/09/20 19:22:17 OK 20251210153512_drop_unused_gin_index.sql (709.38µs)10952026/09/20 19:22:17 OK 20251218171726_add_pins.sql (2.54ms)10962026/09/20 19:22:17 OK 20251218171726_add_pins.sql (1.93ms)10972026/09/20 19:22:17 OK 20260628120000_add_object_size_and_stats.sql (2.98ms)10982026-09-20 19:22:17.548 UTC [84723] ERROR: relation "goose_db_version" does not exist at character 3610992026-09-20 19:22:17.548 UTC [84723] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11002026/09/20 19:22:17 OK 20260905000000_add_claims.sql (13.21ms)11012026/09/20 19:22:17 OK 20260628120000_add_object_size_and_stats.sql (17.21ms)11022026/09/20 19:22:17 OK 20260920000000_drop_claims.sql (1.32ms)11032026/09/20 19:22:17 goose: successfully migrated database to version: 2026092000000011042026/09/20 19:22:17 OK 1_commit_pending_closure.sql (1.46ms)11052026/09/20 19:22:17 OK 20241026095416_initial_model.sql (24.65ms)11062026/09/20 19:22:17 OK 2_object_stats_trigger.sql (391.75µs)11072026/09/20 19:22:17 goose: up to current file version: 211082026/09/20 19:22:17 OK 20251210153512_drop_unused_gin_index.sql (665µs)11092026/09/20 19:22:17 OK 20260905000000_add_claims.sql (3.45ms)11102026/09/20 19:22:17 OK 20251218171726_add_pins.sql (2.08ms)11112026/09/20 19:22:17 OK 20260920000000_drop_claims.sql (18.44ms)11122026/09/20 19:22:17 goose: successfully migrated database to version: 2026092000000011132026/09/20 19:22:17 OK 1_commit_pending_closure.sql (1.38ms)11142026/09/20 19:22:17 OK 2_object_stats_trigger.sql (284.08µs)11152026/09/20 19:22:17 goose: up to current file version: 211162026/09/20 19:22:17 OK 20260628120000_add_object_size_and_stats.sql (31.27ms)11172026/09/20 19:22:17 OK 20260905000000_add_claims.sql (14.12ms)11182026/09/20 19:22:17 OK 20260920000000_drop_claims.sql (9.64ms)11192026/09/20 19:22:17 goose: successfully migrated database to version: 2026092000000011202026/09/20 19:22:17 OK 1_commit_pending_closure.sql (1.63ms)11212026/09/20 19:22:17 OK 2_object_stats_trigger.sql (325.5µs)11222026/09/20 19:22:17 goose: up to current file version: 211232026/09/20 19:22:17 OK 20241026095416_initial_model.sql (66.32ms)11242026/09/20 19:22:17 OK 20251210153512_drop_unused_gin_index.sql (15.76ms)11252026/09/20 19:22:17 OK 20251218171726_add_pins.sql (20.88ms)11262026/09/20 19:22:17 OK 20260628120000_add_object_size_and_stats.sql (23.69ms)11272026/09/20 19:22:17 OK 20260905000000_add_claims.sql (22.33ms)11282026/09/20 19:22:17 OK 20260920000000_drop_claims.sql (34.45ms)11292026/09/20 19:22:17 goose: successfully migrated database to version: 2026092000000011302026/09/20 19:22:17 OK 1_commit_pending_closure.sql (7.53ms)11312026/09/20 19:22:17 OK 2_object_stats_trigger.sql (1.42ms)11322026/09/20 19:22:17 goose: up to current file version: 21133--- PASS: TestReadProxyConditionalGet (1.33s)1134=== CONT TestResurrectedObjectNotDeleted11352026-09-20 19:22:17.900 UTC [84726] ERROR: relation "goose_db_version" does not exist at character 3611362026-09-20 19:22:17.900 UTC [84726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026-09-20 19:22:17.900 UTC [84727] ERROR: relation "goose_db_version" does not exist at character 3611382026-09-20 19:22:17.900 UTC [84727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1139--- PASS: TestReadProxyHead (1.39s)1140=== CONT TestClientIntegration11412026/09/20 19:22:18 OK 20241026095416_initial_model.sql (68.89ms)11422026/09/20 19:22:18 OK 20241026095416_initial_model.sql (68.93ms)11432026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (6.7ms)11442026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (6.76ms)11452026-09-20 19:22:18.014 UTC [84730] ERROR: relation "goose_db_version" does not exist at character 3611462026-09-20 19:22:18.014 UTC [84730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11472026/09/20 19:22:18 OK 20251218171726_add_pins.sql (4.49ms)11482026/09/20 19:22:18 OK 20251218171726_add_pins.sql (4.59ms)11492026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (20.94ms)11502026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (21.06ms)11512026/09/20 19:22:18 OK 20260905000000_add_claims.sql (16.7ms)11522026/09/20 19:22:18 OK 20260905000000_add_claims.sql (16.98ms)11532026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (23.16ms)11542026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000011552026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (23.1ms)11562026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000011572026/09/20 19:22:18 OK 1_commit_pending_closure.sql (3.74ms)11582026/09/20 19:22:18 OK 1_commit_pending_closure.sql (3.67ms)11592026/09/20 19:22:18 OK 2_object_stats_trigger.sql (673.92µs)11602026/09/20 19:22:18 goose: up to current file version: 211612026/09/20 19:22:18 OK 2_object_stats_trigger.sql (649.67µs)11622026/09/20 19:22:18 goose: up to current file version: 21163--- PASS: TestReadProxyInvalidPath (1.42s)1164=== CONT TestOrphanedObjectsGCStressTest11652026/09/20 19:22:18 OK 20241026095416_initial_model.sql (73.86ms)11662026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (4.39ms)11672026/09/20 19:22:18 OK 20251218171726_add_pins.sql (14.36ms)11682026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (16.72ms)11692026/09/20 19:22:18 OK 20260905000000_add_claims.sql (17.78ms)11702026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (16.88ms)11712026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000011722026/09/20 19:22:18 OK 1_commit_pending_closure.sql (3.33ms)11732026/09/20 19:22:18 OK 2_object_stats_trigger.sql (949.83µs)11742026/09/20 19:22:18 goose: up to current file version: 211752026-09-20 19:22:18.268 UTC [84733] ERROR: relation "goose_db_version" does not exist at character 3611762026-09-20 19:22:18.268 UTC [84733] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1177--- PASS: TestReadProxy404 (1.55s)1178=== CONT TestClientErrorHandling1179=== RUN TestClientErrorHandling/InvalidStorePath1180=== PAUSE TestClientErrorHandling/InvalidStorePath1181=== RUN TestClientErrorHandling/InvalidAuthToken1182=== PAUSE TestClientErrorHandling/InvalidAuthToken1183=== RUN TestClientErrorHandling/ServerNotAvailable1184=== PAUSE TestClientErrorHandling/ServerNotAvailable1185=== CONT TestOrphanedObjectsGC11862026-09-20 19:22:18.330 UTC [84736] ERROR: relation "goose_db_version" does not exist at character 3611872026-09-20 19:22:18.330 UTC [84736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026/09/20 19:22:18 OK 20241026095416_initial_model.sql (71.73ms)11892026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (7.72ms)11902026/09/20 19:22:18 OK 20251218171726_add_pins.sql (13.54ms)11912026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (13.55ms)11922026/09/20 19:22:18 OK 20260905000000_add_claims.sql (24.04ms)11932026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (17.26ms)11942026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000011952026/09/20 19:22:18 OK 20241026095416_initial_model.sql (75.25ms)11962026/09/20 19:22:18 OK 1_commit_pending_closure.sql (3.94ms)11972026/09/20 19:22:18 OK 2_object_stats_trigger.sql (782.04µs)11982026/09/20 19:22:18 goose: up to current file version: 211992026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (14.41ms)12002026/09/20 19:22:18 OK 20251218171726_add_pins.sql (10.03ms)1201--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.63s)1202=== CONT TestObjectStatsTrigger12032026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (21.65ms)12042026/09/20 19:22:18 OK 20260905000000_add_claims.sql (16.47ms)12052026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (3.54ms)12062026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000012072026/09/20 19:22:18 OK 1_commit_pending_closure.sql (1.96ms)12082026/09/20 19:22:18 OK 2_object_stats_trigger.sql (451.25µs)12092026/09/20 19:22:18 goose: up to current file version: 212102026-09-20 19:22:18.575 UTC [84739] ERROR: relation "goose_db_version" does not exist at character 3612112026-09-20 19:22:18.575 UTC [84739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1212--- PASS: TestReadProxyNarStreaming (1.81s)1213=== CONT TestMultipartCleanup12142026/09/20 19:22:18 OK 20241026095416_initial_model.sql (56.62ms)12152026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)12162026/09/20 19:22:18 OK 20251218171726_add_pins.sql (13.4ms)12172026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (15.98ms)12182026/09/20 19:22:18 OK 20260905000000_add_claims.sql (15.09ms)12192026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (17.42ms)12202026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000012212026/09/20 19:22:18 OK 1_commit_pending_closure.sql (5.51ms)12222026/09/20 19:22:18 OK 2_object_stats_trigger.sql (633.17µs)12232026/09/20 19:22:18 goose: up to current file version: 212242026-09-20 19:22:18.771 UTC [84742] ERROR: relation "goose_db_version" does not exist at character 3612252026-09-20 19:22:18.771 UTC [84742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1226--- PASS: TestReadProxyNarinfo (1.86s)1227=== CONT TestServerTLSConfig1228=== RUN TestServerTLSConfig/no_client_CA1229=== PAUSE TestServerTLSConfig/no_client_CA1230=== RUN TestServerTLSConfig/missing_CA_file1231=== PAUSE TestServerTLSConfig/missing_CA_file1232=== RUN TestServerTLSConfig/not_a_PEM_file1233=== PAUSE TestServerTLSConfig/not_a_PEM_file1234=== CONT TestService_NativeMTLS12352026/09/20 19:22:18 OK 20241026095416_initial_model.sql (57.37ms)12362026/09/20 19:22:18 OK 20251210153512_drop_unused_gin_index.sql (7.22ms)12372026/09/20 19:22:18 OK 20251218171726_add_pins.sql (8.76ms)12382026/09/20 19:22:18 OK 20260628120000_add_object_size_and_stats.sql (19.68ms)12392026-09-20 19:22:18.937 UTC [84745] ERROR: relation "goose_db_version" does not exist at character 3612402026-09-20 19:22:18.937 UTC [84745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12412026/09/20 19:22:18 OK 20260905000000_add_claims.sql (62.73ms)12422026/09/20 19:22:18 OK 20260920000000_drop_claims.sql (20.22ms)12432026/09/20 19:22:18 goose: successfully migrated database to version: 2026092000000012442026/09/20 19:22:18 OK 1_commit_pending_closure.sql (5.22ms)12452026/09/20 19:22:18 OK 2_object_stats_trigger.sql (2.47ms)12462026/09/20 19:22:18 goose: up to current file version: 212472026/09/20 19:22:19 OK 20241026095416_initial_model.sql (58.65ms)12482026/09/20 19:22:19 OK 20251210153512_drop_unused_gin_index.sql (8.33ms)12492026/09/20 19:22:19 OK 20251218171726_add_pins.sql (7.85ms)12502026/09/20 19:22:19 OK 20260628120000_add_object_size_and_stats.sql (10.48ms)12512026/09/20 19:22:19 OK 20260905000000_add_claims.sql (20.86ms)12522026-09-20 19:22:19.096 UTC [84748] ERROR: relation "goose_db_version" does not exist at character 3612532026-09-20 19:22:19.096 UTC [84748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/09/20 19:22:19 OK 20260920000000_drop_claims.sql (15.18ms)12552026/09/20 19:22:19 goose: successfully migrated database to version: 2026092000000012562026/09/20 19:22:19 OK 1_commit_pending_closure.sql (1.12ms)12572026/09/20 19:22:19 OK 2_object_stats_trigger.sql (285.21µs)12582026/09/20 19:22:19 goose: up to current file version: 212592026/09/20 19:22:19 OK 20241026095416_initial_model.sql (40.13ms)12602026/09/20 19:22:19 OK 20251210153512_drop_unused_gin_index.sql (8.35ms)12612026/09/20 19:22:19 OK 20251218171726_add_pins.sql (7.87ms)12622026/09/20 19:22:19 OK 20260628120000_add_object_size_and_stats.sql (12.94ms)12632026/09/20 19:22:19 OK 20260905000000_add_claims.sql (1.88ms)12642026/09/20 19:22:19 OK 20260920000000_drop_claims.sql (2.47ms)12652026/09/20 19:22:19 goose: successfully migrated database to version: 2026092000000012662026/09/20 19:22:19 OK 1_commit_pending_closure.sql (922.21µs)12672026/09/20 19:22:19 OK 2_object_stats_trigger.sql (248.38µs)12682026/09/20 19:22:19 goose: up to current file version: 212692026-09-20 19:22:19.209 UTC [84753] ERROR: relation "goose_db_version" does not exist at character 3612702026-09-20 19:22:19.209 UTC [84753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1271=== NAME TestClientMultipleUploads1272 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-84476-2894457087/TestClientMultipleUploads324379665/001/store/09z4sx9pv6bj8v67rjzjdik24xh3cvbz-test-file-0.txt12732026/09/20 19:22:19 OK 20241026095416_initial_model.sql (32.69ms)12742026/09/20 19:22:19 OK 20251210153512_drop_unused_gin_index.sql (3.53ms)12752026/09/20 19:22:19 OK 20251218171726_add_pins.sql (11.6ms)12762026/09/20 19:22:19 OK 20260628120000_add_object_size_and_stats.sql (13.41ms)1277 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-84476-2894457087/TestClientMultipleUploads324379665/001/store/0kfavfmanq2ckv75r7kvyvzfv3sqqicd-test-file-1.txt1278=== NAME TestClientWithDependencies1279 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-84476-2894457087/TestClientWithDependencies3084881044/001/store/66i7a2408711m54157krk3wc7y4r320b-test-script12802026/09/20 19:22:19 OK 20260905000000_add_claims.sql (16.62ms)12812026/09/20 19:22:19 OK 20260920000000_drop_claims.sql (14.42ms)12822026/09/20 19:22:19 goose: successfully migrated database to version: 2026092000000012832026/09/20 19:22:19 OK 1_commit_pending_closure.sql (1.44ms)12842026/09/20 19:22:19 OK 2_object_stats_trigger.sql (535.25µs)12852026/09/20 19:22:19 goose: up to current file version: 212862026-09-20 19:22:19.328 UTC [84760] ERROR: relation "goose_db_version" does not exist at character 3612872026-09-20 19:22:19.328 UTC [84760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1288 client_integration_test.go:615: Found 1 dependencies (including self)1289=== NAME TestClientMultipleUploads1290 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-84476-2894457087/TestClientMultipleUploads324379665/001/store/k8azqacb5h3h6j26m2745s9afvs43ma0-test-file-2.txt12912026/09/20 19:22:19 OK 20241026095416_initial_model.sql (16.79ms)1292--- PASS: TestResurrectedObjectNotDeleted (1.62s)1293=== CONT TestMetricsInventory12942026/09/20 19:22:19 OK 20251210153512_drop_unused_gin_index.sql (6.04ms)12952026-09-20 19:22:19.378 UTC [84765] ERROR: relation "goose_db_version" does not exist at character 3612962026-09-20 19:22:19.378 UTC [84765] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12972026/09/20 19:22:19 OK 20251218171726_add_pins.sql (7.74ms)12982026/09/20 19:22:19 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)12992026/09/20 19:22:19 OK 20260905000000_add_claims.sql (11.03ms)13002026/09/20 19:22:19 OK 20260920000000_drop_claims.sql (7.65ms)13012026/09/20 19:22:19 goose: successfully migrated database to version: 2026092000000013022026/09/20 19:22:19 OK 1_commit_pending_closure.sql (848.75µs)13032026/09/20 19:22:19 OK 2_object_stats_trigger.sql (220.17µs)13042026/09/20 19:22:19 goose: up to current file version: 213052026/09/20 19:22:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13062026/09/20 19:22:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13072026/09/20 19:22:19 INFO Received uploads request method=POST path=/api/pending_closures13082026/09/20 19:22:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13092026/09/20 19:22:19 INFO Uploading 66i7a2408711m54157krk3wc7y4r320b-test-script (136B)13102026/09/20 19:22:19 OK 20241026095416_initial_model.sql (44.05ms)13112026/09/20 19:22:19 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13122026/09/20 19:22:19 WARN Failed to register uploaded object key=log/rpyr86f5jrgcxx4li0yzhzazpy96hczr-test-script.drv error="server returned 404: 404 page not found\n"13132026/09/20 19:22:19 OK 20251210153512_drop_unused_gin_index.sql (5.93ms)13142026/09/20 19:22:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13152026/09/20 19:22:19 WARN Failed to register uploaded object key=66i7a2408711m54157krk3wc7y4r320b.ls error="server returned 404: 404 page not found\n"13162026/09/20 19:22:19 INFO Signed narinfos id=1 count=113172026/09/20 19:22:19 INFO Uploading 1 narinfos13182026/09/20 19:22:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13192026/09/20 19:22:19 WARN Failed to register uploaded object key=66i7a2408711m54157krk3wc7y4r320b.narinfo error="server returned 404: 404 page not found\n"13202026/09/20 19:22:19 OK 20251218171726_add_pins.sql (12.92ms)13212026/09/20 19:22:19 INFO Completed upload id=113222026/09/20 19:22:19 INFO Upload complete. (80ms)1323=== NAME TestClientWithDependencies1324 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-84476-2894457087/TestClientWithDependencies3084881044/001/store) requires matching store prefix13252026/09/20 19:22:19 INFO Received uploads request method=POST path=/api/pending_closures13262026/09/20 19:22:19 OK 20260628120000_add_object_size_and_stats.sql (11.35ms)13272026/09/20 19:22:19 INFO Received uploads request method=POST path=/api/pending_closures1328--- PASS: TestClientWithDependencies (2.22s)1329=== CONT TestClientCADerivations13302026/09/20 19:22:19 OK 20260905000000_add_claims.sql (1.57ms)13312026/09/20 19:22:19 INFO Received uploads request method=POST path=/api/pending_closures13322026/09/20 19:22:19 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13332026/09/20 19:22:19 INFO Uploading 0kfavfmanq2ckv75r7kvyvzfv3sqqicd-test-file-1.txt (160B)13342026/09/20 19:22:19 INFO Uploading k8azqacb5h3h6j26m2745s9afvs43ma0-test-file-2.txt (160B)13352026/09/20 19:22:19 INFO Uploading 09z4sx9pv6bj8v67rjzjdik24xh3cvbz-test-file-0.txt (160B)13362026/09/20 19:22:19 OK 20260920000000_drop_claims.sql (11.81ms)13372026/09/20 19:22:19 goose: successfully migrated database to version: 2026092000000013382026/09/20 19:22:19 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13392026/09/20 19:22:19 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13402026/09/20 19:22:19 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13412026/09/20 19:22:19 OK 1_commit_pending_closure.sql (2.05ms)13422026/09/20 19:22:19 OK 2_object_stats_trigger.sql (315.42µs)13432026/09/20 19:22:19 goose: up to current file version: 213442026/09/20 19:22:19 WARN Failed to register uploaded object key=0kfavfmanq2ckv75r7kvyvzfv3sqqicd.ls error="server returned 404: 404 page not found\n"13452026/09/20 19:22:19 WARN Failed to register uploaded object key=09z4sx9pv6bj8v67rjzjdik24xh3cvbz.ls error="server returned 404: 404 page not found\n"13462026/09/20 19:22:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13472026/09/20 19:22:19 WARN Failed to register uploaded object key=k8azqacb5h3h6j26m2745s9afvs43ma0.ls error="server returned 404: 404 page not found\n"13482026/09/20 19:22:19 INFO Signed narinfos id=1 count=113492026/09/20 19:22:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13502026/09/20 19:22:19 INFO Signed narinfos id=2 count=113512026/09/20 19:22:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign13522026/09/20 19:22:19 INFO Signed narinfos id=3 count=113532026/09/20 19:22:19 INFO Uploading 3 narinfos13542026/09/20 19:22:19 WARN Failed to register uploaded object key=k8azqacb5h3h6j26m2745s9afvs43ma0.narinfo error="server returned 404: 404 page not found\n"13552026/09/20 19:22:19 WARN Failed to register uploaded object key=09z4sx9pv6bj8v67rjzjdik24xh3cvbz.narinfo error="server returned 404: 404 page not found\n"13562026/09/20 19:22:19 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13572026/09/20 19:22:19 WARN Failed to register uploaded object key=0kfavfmanq2ckv75r7kvyvzfv3sqqicd.narinfo error="server returned 404: 404 page not found\n"13582026/09/20 19:22:19 INFO Completed upload id=313592026/09/20 19:22:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13602026/09/20 19:22:19 INFO Completed upload id=113612026/09/20 19:22:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13622026/09/20 19:22:19 INFO Completed upload id=213632026/09/20 19:22:19 INFO Upload complete. (130ms)1364=== NAME TestClientMultipleUploads1365 client_integration_test.go:369: Uploaded 3 paths in 159.556667ms1366--- PASS: TestClientMultipleUploads (2.05s)1367=== CONT TestNARDeduplicationMetadataUploadBug1368=== NAME TestClientIntegration1369 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-84476-2894457087/TestClientIntegration3454591984/002/store/h13d0mdqp6nmjsgv31qx47b19k3hq9q5-test-file.txt13702026/09/20 19:22:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13712026/09/20 19:22:19 INFO Received uploads request method=POST path=/api/pending_closures13722026/09/20 19:22:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13732026/09/20 19:22:19 INFO Uploading h13d0mdqp6nmjsgv31qx47b19k3hq9q5-test-file.txt (152B)13742026/09/20 19:22:19 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13752026/09/20 19:22:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13762026/09/20 19:22:19 INFO Signed narinfos id=1 count=113772026/09/20 19:22:19 INFO Uploading 1 narinfos13782026/09/20 19:22:19 WARN Failed to register uploaded object key=h13d0mdqp6nmjsgv31qx47b19k3hq9q5.ls error="server returned 404: 404 page not found\n"13792026/09/20 19:22:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13802026/09/20 19:22:19 WARN Failed to register uploaded object key=h13d0mdqp6nmjsgv31qx47b19k3hq9q5.narinfo error="server returned 404: 404 page not found\n"13812026/09/20 19:22:19 INFO Completed upload id=113822026/09/20 19:22:19 INFO Upload complete. (134ms)13832026/09/20 19:22:19 INFO All 1 paths already cached1384 client_integration_test.go:312: Retrieved narinfo from S3:1385 StorePath: /nix/var/nix/builds/nix-84476-2894457087/TestClientIntegration3454591984/002/store/h13d0mdqp6nmjsgv31qx47b19k3hq9q5-test-file.txt1386 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1387 Compression: zstd1388 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11389 NarSize: 1521390 References: 1391 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11392 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1393 client_integration_test.go:313: Decompressed .ls content (64 bytes):1394 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1395 client_integration_test.go:316: Testing garbage collection...13962026/09/20 19:22:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures13972026/09/20 19:22:19 INFO Garbage collection started13982026/09/20 19:22:19 INFO Aborted multipart uploads count=013992026/09/20 19:22:19 WARN Force mode enabled - objects will be deleted immediately without grace period14002026-09-20 19:22:19.819 UTC [84792] ERROR: relation "goose_db_version" does not exist at character 3614012026-09-20 19:22:19.819 UTC [84792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1402--- PASS: TestObjectStatsTrigger (1.38s)1403=== CONT TestCacheStatsHandler14042026/09/20 19:22:19 OK 20241026095416_initial_model.sql (28.5ms)14052026/09/20 19:22:19 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)14062026/09/20 19:22:19 OK 20251218171726_add_pins.sql (10.75ms)14072026/09/20 19:22:19 OK 20260628120000_add_object_size_and_stats.sql (1.73ms)14082026/09/20 19:22:19 OK 20260905000000_add_claims.sql (16.13ms)14092026/09/20 19:22:19 OK 20260920000000_drop_claims.sql (11.42ms)14102026/09/20 19:22:19 goose: successfully migrated database to version: 2026092000000014112026/09/20 19:22:19 OK 1_commit_pending_closure.sql (1.25ms)14122026/09/20 19:22:19 OK 2_object_stats_trigger.sql (274.67µs)14132026/09/20 19:22:19 goose: up to current file version: 214142026-09-20 19:22:19.950 UTC [84796] ERROR: relation "goose_db_version" does not exist at character 3614152026-09-20 19:22:19.950 UTC [84796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14162026/09/20 19:22:19 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=014172026/09/20 19:22:19 INFO Vacuumed table table=pending_closures14182026/09/20 19:22:20 INFO Received uploads request method=POST path=/api/pending_closures14192026/09/20 19:22:20 INFO Vacuumed table table=pending_objects14202026/09/20 19:22:20 INFO Vacuumed table table=multipart_uploads14212026/09/20 19:22:20 INFO Vacuumed table table=closures14222026/09/20 19:22:20 INFO Vacuumed table table=objects14232026/09/20 19:22:20 OK 20241026095416_initial_model.sql (77.36ms)14242026/09/20 19:22:20 OK 20251210153512_drop_unused_gin_index.sql (1ms)14252026/09/20 19:22:20 OK 20251218171726_add_pins.sql (3.1ms)14262026/09/20 19:22:20 OK 20260628120000_add_object_size_and_stats.sql (20.99ms)14272026/09/20 19:22:20 OK 20260905000000_add_claims.sql (8.22ms)14282026/09/20 19:22:20 OK 20260920000000_drop_claims.sql (7.16ms)14292026/09/20 19:22:20 goose: successfully migrated database to version: 2026092000000014302026/09/20 19:22:20 OK 1_commit_pending_closure.sql (1.27ms)14312026/09/20 19:22:20 OK 2_object_stats_trigger.sql (286.33µs)14322026/09/20 19:22:20 goose: up to current file version: 214332026-09-20 19:22:20.102 UTC [84797] ERROR: relation "goose_db_version" does not exist at character 3614342026-09-20 19:22:20.102 UTC [84797] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026/09/20 19:22:20 INFO Received cleanup request method=DELETE path=/api/pending_closures14362026/09/20 19:22:20 INFO Aborted multipart uploads count=11437--- PASS: TestMultipartCleanup (1.52s)1438=== CONT TestCreatePendingClosureRejectsOversizedNAR14392026/09/20 19:22:20 INFO Received uploads request method=POST path=/api/pending_closures1440--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1441=== CONT TestCacheConfigHandlerMaxNarSize1442--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1443=== CONT TestGenerateLandingPage1444=== NAME TestOrphanedObjectsGC1445 orphaned_objects_gc_test.go:290: GC Test Summary:1446 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1447 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1448 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1449 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1450 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1451--- PASS: TestOrphanedObjectsGC (1.87s)1452=== CONT TestService_readinessHandler1453--- PASS: TestGenerateLandingPage (0.00s)1454=== CONT TestService_AuthMiddleware_OIDC14552026/09/20 19:22:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59679/oidc14562026/09/20 19:22:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14572026/09/20 19:22:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1458--- PASS: TestService_NativeMTLS (1.37s)1459=== CONT TestService_healthCheckHandler14602026/09/20 19:22:20 OK 20241026095416_initial_model.sql (58.3ms)14612026/09/20 19:22:20 OK 20251210153512_drop_unused_gin_index.sql (7.78ms)14622026/09/20 19:22:20 OK 20251218171726_add_pins.sql (7.97ms)14632026/09/20 19:22:20 OK 20260628120000_add_object_size_and_stats.sql (14.07ms)14642026/09/20 19:22:20 OK 20260905000000_add_claims.sql (19.26ms)14652026/09/20 19:22:20 OK 20260920000000_drop_claims.sql (7.9ms)14662026/09/20 19:22:20 goose: successfully migrated database to version: 2026092000000014672026/09/20 19:22:20 OK 1_commit_pending_closure.sql (1.66ms)14682026/09/20 19:22:20 OK 2_object_stats_trigger.sql (404.71µs)14692026/09/20 19:22:20 goose: up to current file version: 21470--- PASS: TestMetricsInventory (1.01s)1471=== CONT TestService_ReadScope_PublicByDefault14722026/09/20 19:22:20 WARN Rate limiter enabled after throttle name=s3-test rate=514732026/09/20 19:22:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1474=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1475 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101476 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001477--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.30s)1478=== CONT TestGracefulShutdownDrainsInflight14792026/09/20 19:22:20 INFO Starting HTTP server address=127.0.0.1:5968414802026/09/20 19:22:20 INFO Shutdown signal received, draining in-flight requests timeout=10s1481--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1482=== CONT TestService_RequireScope_OIDC14832026/09/20 19:22:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59688/oidc14842026-09-20 19:22:20.871 UTC [84812] ERROR: relation "goose_db_version" does not exist at character 3614852026-09-20 19:22:20.871 UTC [84812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14862026/09/20 19:22:20 OK 20241026095416_initial_model.sql (7.83ms)14872026/09/20 19:22:20 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)14882026/09/20 19:22:20 OK 20251218171726_add_pins.sql (1.86ms)14892026/09/20 19:22:20 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)14902026/09/20 19:22:20 OK 20260905000000_add_claims.sql (2.39ms)14912026/09/20 19:22:20 OK 20260920000000_drop_claims.sql (1.27ms)14922026/09/20 19:22:20 goose: successfully migrated database to version: 2026092000000014932026/09/20 19:22:20 OK 1_commit_pending_closure.sql (1.53ms)14942026/09/20 19:22:20 OK 2_object_stats_trigger.sql (579.92µs)14952026/09/20 19:22:20 goose: up to current file version: 21496=== NAME TestNARDeduplicationMetadataUploadBug1497 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-84476-2894457087/TestNARDeduplicationMetadataUploadBug3327979361/001/store/vv1w0d1dxlmba4lzbmclgw2bx5hlsmk4-file1.txt1498=== NAME TestClientCADerivations1499 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-84476-2894457087/TestClientCADerivations2069860095/001/store/j7i8n424y1ibr3ihccypvny52wvjq1z7-ca-test1500 client_ca_test.go:139: Found 1 dependencies (including self)15012026/09/20 19:22:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1502--- PASS: TestCacheStatsHandler (1.26s)1503=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15042026/09/20 19:22:21 INFO Received uploads request method=POST path=/api/pending_closures15052026/09/20 19:22:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15062026/09/20 19:22:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15072026/09/20 19:22:21 INFO Uploading vv1w0d1dxlmba4lzbmclgw2bx5hlsmk4-file1.txt (160B)15082026/09/20 19:22:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15092026/09/20 19:22:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15102026/09/20 19:22:21 WARN Failed to register uploaded object key=vv1w0d1dxlmba4lzbmclgw2bx5hlsmk4.ls error="server returned 404: 404 page not found\n"15112026/09/20 19:22:21 INFO Signed narinfos id=1 count=115122026/09/20 19:22:21 INFO Uploading 1 narinfos15132026/09/20 19:22:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15142026/09/20 19:22:21 WARN Failed to register uploaded object key=vv1w0d1dxlmba4lzbmclgw2bx5hlsmk4.narinfo error="server returned 404: 404 page not found\n"15152026/09/20 19:22:21 INFO Received uploads request method=POST path=/api/pending_closures15162026-09-20 19:22:21.218 UTC [84831] ERROR: relation "goose_db_version" does not exist at character 3615172026-09-20 19:22:21.218 UTC [84831] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15182026/09/20 19:22:21 INFO Completed upload id=115192026/09/20 19:22:21 INFO Upload complete. (187ms)15202026/09/20 19:22:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15212026/09/20 19:22:21 INFO Uploading j7i8n424y1ibr3ihccypvny52wvjq1z7-ca-test (144B)1522=== NAME TestNARDeduplicationMetadataUploadBug1523 metadata_upload_test.go:54: Retrieved narinfo from S3:1524 StorePath: /nix/var/nix/builds/nix-84476-2894457087/TestNARDeduplicationMetadataUploadBug3327979361/001/store/vv1w0d1dxlmba4lzbmclgw2bx5hlsmk4-file1.txt1525 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1526 Compression: zstd1527 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1528 NarSize: 1601529 References: 1530 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1531 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1532 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1533 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15342026/09/20 19:22:21 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15352026/09/20 19:22:21 WARN Failed to register uploaded object key=log/gn1md4pn0y50b5n0gzx0g7wdi837yyay-ca-test.drv error="server returned 404: 404 page not found\n"15362026/09/20 19:22:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15372026/09/20 19:22:21 INFO Signed narinfos id=1 count=115382026/09/20 19:22:21 WARN Failed to register uploaded object key=j7i8n424y1ibr3ihccypvny52wvjq1z7.ls error="server returned 404: 404 page not found\n"15392026/09/20 19:22:21 INFO Uploading 1 narinfos15402026/09/20 19:22:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15412026/09/20 19:22:21 WARN Failed to register uploaded object key=j7i8n424y1ibr3ihccypvny52wvjq1z7.narinfo error="server returned 404: 404 page not found\n"15422026/09/20 19:22:21 INFO Completed upload id=115432026/09/20 19:22:21 INFO Upload complete. (178ms)1544=== NAME TestClientCADerivations1545 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-84476-2894457087/TestClientCADerivations2069860095/001/store/j7i8n424y1ibr3ihccypvny52wvjq1z7-ca-test1546 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1547 Compression: zstd1548 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1549 NarSize: 1441550 References: 1551 Deriver: /nix/var/nix/builds/nix-84476-2894457087/TestClientCADerivations2069860095/001/store/gn1md4pn0y50b5n0gzx0g7wdi837yyay-ca-test.drv1552 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1553 client_ca_test.go:185: Checking for realisation files in S3...1554 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1555 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1556=== NAME TestNARDeduplicationMetadataUploadBug1557 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-84476-2894457087/TestNARDeduplicationMetadataUploadBug3327979361/001/store/i7vd15mc027dwbmzrqx0z7rk46139jyb-file2.txt15582026/09/20 19:22:21 OK 20241026095416_initial_model.sql (87.68ms)15592026/09/20 19:22:21 OK 20251210153512_drop_unused_gin_index.sql (9.03ms)15602026/09/20 19:22:21 OK 20251218171726_add_pins.sql (9.39ms)15612026-09-20 19:22:21.373 UTC [84840] ERROR: relation "goose_db_version" does not exist at character 3615622026-09-20 19:22:21.373 UTC [84840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15632026-09-20 19:22:21.374 UTC [84841] ERROR: relation "goose_db_version" does not exist at character 3615642026-09-20 19:22:21.374 UTC [84841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15652026-09-20 19:22:21.391 UTC [84842] ERROR: relation "goose_db_version" does not exist at character 3615662026-09-20 19:22:21.391 UTC [84842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1567=== NAME TestClientCADerivations1568 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket34?endpoint=http://localhost:59577®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-84476-2894457087/TestClientCADerivations2069860095/001/store'1569 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115702026/09/20 19:22:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15712026/09/20 19:22:21 OK 20260628120000_add_object_size_and_stats.sql (23.91ms)15722026/09/20 19:22:21 OK 20260905000000_add_claims.sql (34.03ms)15732026/09/20 19:22:21 INFO Received uploads request method=POST path=/api/pending_closures15742026/09/20 19:22:21 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15752026/09/20 19:22:21 OK 20260920000000_drop_claims.sql (10.74ms)15762026/09/20 19:22:21 goose: successfully migrated database to version: 202609200000001577--- PASS: TestClientCADerivations (1.97s)1578=== CONT TestRedundantMultipartUpload15792026/09/20 19:22:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15802026/09/20 19:22:21 INFO Signed narinfos id=2 count=115812026/09/20 19:22:21 INFO Uploading 1 narinfos15822026/09/20 19:22:21 OK 1_commit_pending_closure.sql (1.9ms)15832026/09/20 19:22:21 WARN Failed to register uploaded object key=i7vd15mc027dwbmzrqx0z7rk46139jyb.ls error="server returned 404: 404 page not found\n"15842026/09/20 19:22:21 OK 2_object_stats_trigger.sql (304.38µs)15852026/09/20 19:22:21 goose: up to current file version: 215862026/09/20 19:22:21 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15872026/09/20 19:22:21 WARN Failed to register uploaded object key=i7vd15mc027dwbmzrqx0z7rk46139jyb.narinfo error="server returned 404: 404 page not found\n"15882026/09/20 19:22:21 INFO Completed upload id=215892026/09/20 19:22:21 INFO Upload complete. (111ms)1590=== NAME TestNARDeduplicationMetadataUploadBug1591 metadata_upload_test.go:76: Retrieved narinfo from S3:1592 StorePath: /nix/var/nix/builds/nix-84476-2894457087/TestNARDeduplicationMetadataUploadBug3327979361/001/store/i7vd15mc027dwbmzrqx0z7rk46139jyb-file2.txt1593 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1594 Compression: zstd1595 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1596 NarSize: 1601597 References: 1598 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1599 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1600 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1601 {"version":1,"root":{"type":"regular","size":44}}1602--- PASS: TestNARDeduplicationMetadataUploadBug (1.96s)1603=== CONT TestCompletedNarNotReofferedAcrossClosures16042026/09/20 19:22:21 OK 20241026095416_initial_model.sql (104.18ms)16052026/09/20 19:22:21 OK 20251210153512_drop_unused_gin_index.sql (8.39ms)16062026/09/20 19:22:21 OK 20241026095416_initial_model.sql (120.81ms)16072026/09/20 19:22:21 OK 20251210153512_drop_unused_gin_index.sql (9.46ms)16082026/09/20 19:22:21 OK 20251218171726_add_pins.sql (30.12ms)16092026/09/20 19:22:21 OK 20241026095416_initial_model.sql (137.81ms)16102026/09/20 19:22:21 OK 20251218171726_add_pins.sql (31.74ms)16112026/09/20 19:22:21 OK 20251210153512_drop_unused_gin_index.sql (7.76ms)16122026/09/20 19:22:21 OK 20260628120000_add_object_size_and_stats.sql (30.14ms)16132026/09/20 19:22:21 OK 20251218171726_add_pins.sql (20ms)16142026/09/20 19:22:21 OK 20260628120000_add_object_size_and_stats.sql (24.4ms)16152026/09/20 19:22:21 OK 20260628120000_add_object_size_and_stats.sql (38.82ms)16162026/09/20 19:22:21 OK 20260905000000_add_claims.sql (55.63ms)16172026/09/20 19:22:21 OK 20260905000000_add_claims.sql (55.6ms)16182026/09/20 19:22:21 OK 20260920000000_drop_claims.sql (27.51ms)16192026/09/20 19:22:21 goose: successfully migrated database to version: 2026092000000016202026/09/20 19:22:21 OK 20260905000000_add_claims.sql (37.22ms)16212026/09/20 19:22:21 OK 1_commit_pending_closure.sql (2.07ms)16222026/09/20 19:22:21 OK 2_object_stats_trigger.sql (402.29µs)16232026/09/20 19:22:21 goose: up to current file version: 216242026/09/20 19:22:21 OK 20260920000000_drop_claims.sql (24.35ms)16252026/09/20 19:22:21 goose: successfully migrated database to version: 2026092000000016262026/09/20 19:22:21 OK 1_commit_pending_closure.sql (1.8ms)16272026/09/20 19:22:21 OK 2_object_stats_trigger.sql (364.75µs)16282026/09/20 19:22:21 goose: up to current file version: 216292026/09/20 19:22:21 OK 20260920000000_drop_claims.sql (31.75ms)16302026/09/20 19:22:21 goose: successfully migrated database to version: 2026092000000016312026/09/20 19:22:21 OK 1_commit_pending_closure.sql (1.81ms)16322026/09/20 19:22:21 OK 2_object_stats_trigger.sql (476.38µs)16332026/09/20 19:22:21 goose: up to current file version: 216342026/09/20 19:22:21 WARN readiness check failed error="closed pool"1635--- PASS: TestService_readinessHandler (1.56s)1636=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16372026/09/20 19:22:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01638=== NAME TestClientIntegration1639 client_integration_test.go:323: Objects in database after GC:1640 client_integration_test.go:323: Successfully deleted all objects with GC --force1641--- PASS: TestClientIntegration (3.84s)1642=== CONT TestService_ReadAuthMiddleware16432026-09-20 19:22:21.846 UTC [84852] ERROR: relation "goose_db_version" does not exist at character 3616442026-09-20 19:22:21.846 UTC [84852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1645--- PASS: TestService_healthCheckHandler (1.79s)1646=== CONT TestPresignedUploadRegisteredBeforeCommit16472026/09/20 19:22:22 OK 20241026095416_initial_model.sql (168ms)16482026/09/20 19:22:22 OK 20251210153512_drop_unused_gin_index.sql (13.3ms)16492026/09/20 19:22:22 OK 20251218171726_add_pins.sql (15.44ms)16502026/09/20 19:22:22 OK 20260628120000_add_object_size_and_stats.sql (31.72ms)16512026/09/20 19:22:22 OK 20260905000000_add_claims.sql (54.4ms)16522026/09/20 19:22:22 OK 20260920000000_drop_claims.sql (25.42ms)16532026/09/20 19:22:22 goose: successfully migrated database to version: 2026092000000016542026/09/20 19:22:22 OK 1_commit_pending_closure.sql (5.08ms)16552026/09/20 19:22:22 OK 2_object_stats_trigger.sql (1.09ms)16562026/09/20 19:22:22 goose: up to current file version: 21657=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1658=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1659=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1660=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1661=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1662=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1663=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1664=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1665=== CONT TestService_AuthMiddleware_MTLSProxyHeader16662026-09-20 19:22:22.447 UTC [84859] ERROR: relation "goose_db_version" does not exist at character 3616672026-09-20 19:22:22.447 UTC [84859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1668--- PASS: TestService_ReadScope_PublicByDefault (2.10s)1669=== CONT TestLeadEndsOnShutdown16702026/09/20 19:22:22 OK 20241026095416_initial_model.sql (68.13ms)16712026/09/20 19:22:22 OK 20251210153512_drop_unused_gin_index.sql (5.78ms)16722026/09/20 19:22:22 OK 20251218171726_add_pins.sql (6.49ms)16732026/09/20 19:22:22 OK 20260628120000_add_object_size_and_stats.sql (29.33ms)16742026/09/20 19:22:22 OK 20260905000000_add_claims.sql (21.31ms)16752026/09/20 19:22:22 OK 20260920000000_drop_claims.sql (29.83ms)16762026/09/20 19:22:22 goose: successfully migrated database to version: 2026092000000016772026/09/20 19:22:22 OK 1_commit_pending_closure.sql (4.61ms)16782026/09/20 19:22:22 OK 2_object_stats_trigger.sql (1.35ms)16792026/09/20 19:22:22 goose: up to current file version: 21680=== RUN TestService_RequireScope_OIDC/builder_may_write1681=== PAUSE TestService_RequireScope_OIDC/builder_may_write1682=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1683=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1684=== RUN TestService_RequireScope_OIDC/ops_may_admin1685=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1686=== RUN TestService_RequireScope_OIDC/ops_may_not_write1687=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1688=== RUN TestService_RequireScope_OIDC/reader_may_not_write1689=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1690=== RUN TestService_RequireScope_OIDC/static_token_may_admin1691=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1692=== RUN TestService_RequireScope_OIDC/static_token_may_write1693=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1694=== RUN TestService_RequireScope_OIDC/reader_may_read1695=== PAUSE TestService_RequireScope_OIDC/reader_may_read1696=== RUN TestService_RequireScope_OIDC/writer_implies_read1697=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1698=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1699=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1700=== CONT TestGCMetrics17012026-09-20 19:22:22.766 UTC [84864] ERROR: relation "goose_db_version" does not exist at character 3617022026-09-20 19:22:22.766 UTC [84864] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17032026-09-20 19:22:22.812 UTC [84865] ERROR: relation "goose_db_version" does not exist at character 3617042026-09-20 19:22:22.812 UTC [84865] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17052026/09/20 19:22:22 INFO Received uploads request method=POST path=/api/pending_closures17062026/09/20 19:22:22 OK 20241026095416_initial_model.sql (139.31ms)17072026/09/20 19:22:22 OK 20251210153512_drop_unused_gin_index.sql (4.13ms)17082026/09/20 19:22:22 OK 20251218171726_add_pins.sql (7.7ms)17092026/09/20 19:22:22 OK 20241026095416_initial_model.sql (89.45ms)17102026/09/20 19:22:22 OK 20251210153512_drop_unused_gin_index.sql (4.27ms)17112026/09/20 19:22:22 OK 20260628120000_add_object_size_and_stats.sql (38.69ms)17122026/09/20 19:22:22 OK 20251218171726_add_pins.sql (13.06ms)17132026/09/20 19:22:23 OK 20260905000000_add_claims.sql (18.46ms)1714=== NAME TestOrphanedObjectsGCStressTest1715 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17162026/09/20 19:22:23 OK 20260920000000_drop_claims.sql (13.61ms)17172026/09/20 19:22:23 goose: successfully migrated database to version: 2026092000000017182026/09/20 19:22:23 OK 20260628120000_add_object_size_and_stats.sql (30.38ms)17192026/09/20 19:22:23 OK 1_commit_pending_closure.sql (5.34ms)17202026/09/20 19:22:23 OK 2_object_stats_trigger.sql (1.1ms)17212026/09/20 19:22:23 goose: up to current file version: 217222026/09/20 19:22:23 OK 20260905000000_add_claims.sql (43.05ms)1723 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17242026/09/20 19:22:23 OK 20260920000000_drop_claims.sql (38.3ms)17252026/09/20 19:22:23 goose: successfully migrated database to version: 2026092000000017262026/09/20 19:22:23 OK 1_commit_pending_closure.sql (3.53ms)17272026/09/20 19:22:23 OK 2_object_stats_trigger.sql (813.04µs)17282026/09/20 19:22:23 goose: up to current file version: 217292026-09-20 19:22:23.112 UTC [84866] ERROR: relation "goose_db_version" does not exist at character 3617302026-09-20 19:22:23.112 UTC [84866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17312026-09-20 19:22:23.122 UTC [84867] ERROR: relation "goose_db_version" does not exist at character 3617322026-09-20 19:22:23.122 UTC [84867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17332026/09/20 19:22:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17342026/09/20 19:22:23 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWNiM2MwMzYtNWQzNy00ODY3LWJiYTgtMTY0ZjJkYWQ0YzIxLmRjN2MzYjU2LTk0MWEtNDk5MC1hZjMyLTQxNDNmMDViMWM3MngxNzg5OTMyMTQyOTU3MDMwMDAw17352026/09/20 19:22:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWNiM2MwMzYtNWQzNy00ODY3LWJiYTgtMTY0ZjJkYWQ0YzIxLmRjN2MzYjU2LTk0MWEtNDk5MC1hZjMyLTQxNDNmMDViMWM3MngxNzg5OTMyMTQyOTU3MDMwMDAw parts=11736--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.06s)1737=== CONT TestGCBugBareHashReferences17382026/09/20 19:22:23 OK 20241026095416_initial_model.sql (87.58ms)17392026-09-20 19:22:23.243 UTC [84870] ERROR: relation "goose_db_version" does not exist at character 3617402026-09-20 19:22:23.243 UTC [84870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17412026/09/20 19:22:23 OK 20251210153512_drop_unused_gin_index.sql (8.14ms)17422026/09/20 19:22:23 OK 20241026095416_initial_model.sql (94.94ms)17432026/09/20 19:22:23 OK 20251210153512_drop_unused_gin_index.sql (8.25ms)17442026/09/20 19:22:23 INFO Received uploads request method=POST path=/api/pending_closures17452026/09/20 19:22:23 OK 20251218171726_add_pins.sql (20.89ms)17462026/09/20 19:22:23 OK 20251218171726_add_pins.sql (29.72ms)17472026/09/20 19:22:23 OK 20260628120000_add_object_size_and_stats.sql (13.94ms)17482026/09/20 19:22:23 OK 20260628120000_add_object_size_and_stats.sql (18.96ms)17492026/09/20 19:22:23 INFO Received uploads request method=POST path=/api/pending_closures17502026/09/20 19:22:23 OK 20260905000000_add_claims.sql (46ms)17512026/09/20 19:22:23 OK 20260905000000_add_claims.sql (49.23ms)17522026/09/20 19:22:23 OK 20260920000000_drop_claims.sql (27.95ms)17532026/09/20 19:22:23 goose: successfully migrated database to version: 2026092000000017542026/09/20 19:22:23 OK 20260920000000_drop_claims.sql (21.11ms)17552026/09/20 19:22:23 goose: successfully migrated database to version: 2026092000000017562026/09/20 19:22:23 OK 1_commit_pending_closure.sql (2.98ms)17572026/09/20 19:22:23 OK 1_commit_pending_closure.sql (2.38ms)17582026/09/20 19:22:23 OK 2_object_stats_trigger.sql (691.83µs)17592026/09/20 19:22:23 goose: up to current file version: 217602026/09/20 19:22:23 OK 2_object_stats_trigger.sql (775.83µs)17612026/09/20 19:22:23 goose: up to current file version: 217622026/09/20 19:22:23 OK 20241026095416_initial_model.sql (107.54ms)17632026/09/20 19:22:23 OK 20251210153512_drop_unused_gin_index.sql (9.38ms)17642026/09/20 19:22:23 OK 20251218171726_add_pins.sql (43.24ms)17652026/09/20 19:22:23 OK 20260628120000_add_object_size_and_stats.sql (32.86ms)17662026/09/20 19:22:23 OK 20260905000000_add_claims.sql (50.89ms)17672026/09/20 19:22:23 OK 20260920000000_drop_claims.sql (17.77ms)17682026/09/20 19:22:23 goose: successfully migrated database to version: 2026092000000017692026/09/20 19:22:23 OK 1_commit_pending_closure.sql (2.94ms)17702026/09/20 19:22:23 OK 2_object_stats_trigger.sql (638.5µs)17712026/09/20 19:22:23 goose: up to current file version: 217722026/09/20 19:22:23 INFO Received uploads request method=POST path=/api/pending_closures17732026-09-20 19:22:23.657 UTC [84871] ERROR: relation "goose_db_version" does not exist at character 3617742026-09-20 19:22:23.657 UTC [84871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17752026/09/20 19:22:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17762026/09/20 19:22:23 WARN mTLS auth: bound subjects configured but subject DN unavailable17772026/09/20 19:22:23 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1778--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.19s)1779=== CONT TestResolveDBConnectionString1780=== RUN TestResolveDBConnectionString/flag_wins1781=== PAUSE TestResolveDBConnectionString/flag_wins1782=== RUN TestResolveDBConnectionString/file_when_flag_empty1783=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1784=== RUN TestResolveDBConnectionString/missing_file_is_an_error1785=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1786=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1787=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1788=== RUN TestResolveDBConnectionString/nothing_configured1789=== PAUSE TestResolveDBConnectionString/nothing_configured1790=== CONT TestLeadElectsOneAndHandsOver17912026/09/20 19:22:23 OK 20241026095416_initial_model.sql (266.21ms)17922026/09/20 19:22:23 OK 20251210153512_drop_unused_gin_index.sql (9.32ms)17932026/09/20 19:22:24 OK 20251218171726_add_pins.sql (38.82ms)17942026/09/20 19:22:24 OK 20260628120000_add_object_size_and_stats.sql (44.46ms)17952026/09/20 19:22:24 OK 20260905000000_add_claims.sql (137.09ms)17962026/09/20 19:22:24 OK 20260920000000_drop_claims.sql (34.03ms)17972026/09/20 19:22:24 goose: successfully migrated database to version: 2026092000000017982026/09/20 19:22:24 OK 1_commit_pending_closure.sql (3.76ms)17992026/09/20 19:22:24 OK 2_object_stats_trigger.sql (781.42µs)18002026/09/20 19:22:24 goose: up to current file version: 21801--- PASS: TestService_ReadAuthMiddleware (2.52s)1802=== CONT TestPinProtectsFromGC18032026-09-20 19:22:24.419 UTC [84876] ERROR: relation "goose_db_version" does not exist at character 3618042026-09-20 19:22:24.419 UTC [84876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18052026/09/20 19:22:24 INFO Received uploads request method=POST path=/api/pending_closures18062026/09/20 19:22:24 OK 20241026095416_initial_model.sql (310.54ms)18072026/09/20 19:22:24 OK 20251210153512_drop_unused_gin_index.sql (9.84ms)18082026/09/20 19:22:24 OK 20251218171726_add_pins.sql (30.81ms)18092026/09/20 19:22:24 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst18102026/09/20 19:22:24 INFO Received uploads request method=POST path=/api/pending_closures1811--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.89s)1812=== CONT TestProxyWriteTimeout/narinfo1813=== CONT TestProxyWriteTimeout/unknown_size1814=== CONT TestProxyWriteTimeout/10_GiB_nar1815=== CONT TestProxyWriteTimeout/1_GiB_nar1816=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1817--- PASS: TestProxyWriteTimeout (0.00s)1818 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1819 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1820 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1821 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)18222026/09/20 19:22:24 INFO Received uploads request method=POST path=/18232026/09/20 19:22:24 OK 20260628120000_add_object_size_and_stats.sql (45.57ms)18242026/09/20 19:22:24 OK 20260905000000_add_claims.sql (58.44ms)18252026/09/20 19:22:24 OK 20260920000000_drop_claims.sql (27.4ms)18262026/09/20 19:22:24 goose: successfully migrated database to version: 2026092000000018272026/09/20 19:22:24 OK 1_commit_pending_closure.sql (1.43ms)18282026/09/20 19:22:24 OK 2_object_stats_trigger.sql (235.17µs)18292026/09/20 19:22:24 goose: up to current file version: 218302026-09-20 19:22:25.002 UTC [84877] ERROR: relation "goose_db_version" does not exist at character 3618312026-09-20 19:22:25.002 UTC [84877] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1832--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.78s)1833=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18342026/09/20 19:22:25 INFO Received request for more parts method=POST path=/1835=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18362026/09/20 19:22:25 INFO Received complete multipart upload request method=POST path=/1837=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18382026/09/20 19:22:25 INFO Received uploads request method=POST path=/1839=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18402026/09/20 19:22:25 INFO Received complete multipart upload request method=POST path=/1841=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18422026/09/20 19:22:25 INFO Received request for more parts method=POST path=/1843=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18442026/09/20 19:22:25 INFO Received uploads request method=POST path=/1845--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1846 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1847 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1848 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1849 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1850=== CONT TestIsValidUploadKey/narinfo1851=== CONT TestIsValidUploadKey/realisation_plus_in_output1852=== CONT TestIsValidUploadKey/realisation1853=== CONT TestIsValidUploadKey/build_log_equals1854=== CONT TestIsValidUploadKey/build_log_question_mark1855=== CONT TestIsValidUploadKey/build_log_plus_in_name1856=== CONT TestIsValidUploadKey/build_log_home-manager_file1857=== CONT TestIsValidUploadKey/build_log1858=== CONT TestIsValidUploadKey/listing1859=== CONT TestIsValidUploadKey/nar_plain1860=== CONT TestIsValidUploadKey/nar_xz1861=== CONT TestIsValidUploadKey/nix-cache-info1862=== CONT TestIsValidUploadKey/nar_zst1863=== CONT TestIsValidUploadKey/traversal1864=== CONT TestIsValidUploadKey/unknown_type1865=== CONT TestIsValidUploadKey/empty_key1866=== CONT TestIsValidUploadKey/absolute1867=== CONT TestIsValidUploadKey/traversal_nar1868=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1869=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1870=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1871=== CONT TestIsValidUploadKey/index.html1872--- PASS: TestIsValidUploadKey (0.00s)1873 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1874 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1875 --- PASS: TestIsValidUploadKey/realisation (0.00s)1876 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1877 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1878 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1879 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1880 --- PASS: TestIsValidUploadKey/build_log (0.00s)1881 --- PASS: TestIsValidUploadKey/listing (0.00s)1882 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1883 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1884 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1885 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1886 --- PASS: TestIsValidUploadKey/traversal (0.00s)1887 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1888 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1889 --- PASS: TestIsValidUploadKey/absolute (0.00s)1890 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1891 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1892 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1893 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1894 --- PASS: TestIsValidUploadKey/index.html (0.00s)1895=== CONT TestIsValidCachePath/narinfo1896=== CONT TestIsValidCachePath/index.html1897=== CONT TestIsValidCachePath/short_hash1898=== CONT TestIsValidCachePath/wrong_extension1899=== CONT TestIsValidCachePath/leading_slash1900=== CONT TestIsValidCachePath/empty1901=== CONT TestIsValidCachePath/random_path1902=== CONT TestIsValidCachePath/invalid_char_u1903=== CONT TestIsValidCachePath/invalid_char_e1904=== CONT TestIsValidCachePath/traversal_in_middle1905=== CONT TestIsValidCachePath/traversal_parent1906=== CONT TestIsValidCachePath/nar_uncompressed1907=== CONT TestIsValidCachePath/nix-cache-info1908=== CONT TestIsValidCachePath/realisation1909=== CONT TestIsValidCachePath/log1910=== CONT TestIsValidCachePath/ls1911=== CONT TestIsValidCachePath/nar_xz1912=== CONT TestIsValidCachePath/nar_bz21913=== CONT TestIsValidCachePath/nar_zst1914=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1915--- PASS: TestIsValidCachePath (0.00s)1916 --- PASS: TestIsValidCachePath/narinfo (0.00s)1917 --- PASS: TestIsValidCachePath/index.html (0.00s)1918 --- PASS: TestIsValidCachePath/short_hash (0.00s)1919 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1920 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1921 --- PASS: TestIsValidCachePath/empty (0.00s)1922 --- PASS: TestIsValidCachePath/random_path (0.00s)1923 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1924 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1925 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1926 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1927 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1928 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1929 --- PASS: TestIsValidCachePath/realisation (0.00s)1930 --- PASS: TestIsValidCachePath/log (0.00s)1931 --- PASS: TestIsValidCachePath/ls (0.00s)1932 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1933 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1934 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1935 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1936=== CONT TestCacheConfigHandler/full_config,_no_issuer1937=== CONT TestCacheConfigHandler/no_signing_keys1938=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1939=== CONT TestCacheConfigHandler/no_cache_url_configured1940--- PASS: TestCacheConfigHandler (0.00s)1941 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1942 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1943 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1944 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1945=== CONT TestParseSingleRange/none1946=== CONT TestParseSingleRange/open-ended1947=== CONT TestParseSingleRange/start_far_past_EOF1948=== CONT TestParseSingleRange/start_past_EOF1949=== CONT TestParseSingleRange/single_byte1950=== CONT TestParseSingleRange/suffix_exceeds_size1951=== CONT TestParseSingleRange/suffix1952=== CONT TestParseSingleRange/end_clamped_to_size1953=== CONT TestParseSingleRange/malformed_both_empty1954=== CONT TestParseSingleRange/closed1955=== CONT TestParseSingleRange/malformed_end_before_start1956=== CONT TestParseSingleRange/multi-range_ignored1957=== CONT TestParseSingleRange/malformed_no_dash1958=== CONT TestParseSingleRange/unknown_unit1959--- PASS: TestParseSingleRange (0.00s)1960 --- PASS: TestParseSingleRange/none (0.00s)1961 --- PASS: TestParseSingleRange/open-ended (0.00s)1962 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1963 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1964 --- PASS: TestParseSingleRange/single_byte (0.00s)1965 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1966 --- PASS: TestParseSingleRange/suffix (0.00s)1967 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1968 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1969 --- PASS: TestParseSingleRange/closed (0.00s)1970 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1971 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1972 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1973 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1974=== CONT TestClientErrorHandling/InvalidStorePath1975--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1976 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1977 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1978 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1979=== CONT TestClientErrorHandling/ServerNotAvailable19802026/09/20 19:22:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19812026/09/20 19:22:25 OK 20241026095416_initial_model.sql (274.78ms)19822026/09/20 19:22:25 INFO lead: acquired remote=192.0.2.1:123419832026/09/20 19:22:25 INFO lead: released remote=192.0.2.1:12341984--- PASS: TestLeadEndsOnShutdown (2.88s)1985=== CONT TestClientErrorHandling/InvalidAuthToken19862026/09/20 19:22:25 OK 20251210153512_drop_unused_gin_index.sql (46.01ms)19872026/09/20 19:22:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWNiM2MwMzYtNWQzNy00ODY3LWJiYTgtMTY0ZjJkYWQ0YzIxLmI4NjM2YmFjLWU4N2QtNGU0Yy04Yjc2LWY2NDZkODA5ZWEzZngxNzg5OTMyMTQzMjk2Mjg1MDAw parts=121988--- PASS: TestRedundantMultipartUpload (4.00s)1989=== CONT TestServerTLSConfig/no_client_CA1990=== CONT TestServerTLSConfig/not_a_PEM_file19912026/09/20 19:22:25 OK 20251218171726_add_pins.sql (42.28ms)1992=== CONT TestServerTLSConfig/missing_CA_file1993--- PASS: TestServerTLSConfig (0.00s)1994 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1995 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)1996 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1997=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1998=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19992026/09/20 19:22:25 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]2000=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2001=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20022026/09/20 19:22:25 OK 20260628120000_add_object_size_and_stats.sql (25.42ms)20032026/09/20 19:22:25 WARN Authentication failed token_preview=eyJhbGciOi...n7XHFgajqA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2004=== CONT TestService_RequireScope_OIDC/builder_may_write2005=== CONT TestService_RequireScope_OIDC/static_token_may_admin2006=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2007=== CONT TestService_RequireScope_OIDC/writer_implies_read2008=== CONT TestService_RequireScope_OIDC/reader_may_read2009=== CONT TestService_RequireScope_OIDC/static_token_may_write2010=== CONT TestService_RequireScope_OIDC/ops_may_not_write2011=== CONT TestService_RequireScope_OIDC/reader_may_not_write2012=== CONT TestService_RequireScope_OIDC/ops_may_admin2013=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2014=== CONT TestResolveDBConnectionString/flag_wins2015=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2016=== CONT TestResolveDBConnectionString/nothing_configured2017=== CONT TestResolveDBConnectionString/missing_file_is_an_error2018=== CONT TestResolveDBConnectionString/file_when_flag_empty2019--- PASS: TestService_RequireScope_OIDC (2.10s)2020 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2021 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2022 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2023 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2024 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2025 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2026 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2027 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2030--- PASS: TestResolveDBConnectionString (0.02s)2031 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2032 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2033 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2034 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2035 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2036--- PASS: TestService_AuthMiddleware_OIDC (2.10s)2037 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2038 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2039 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2040 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20412026/09/20 19:22:25 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/present20422026/09/20 19:22:25 OK 20260905000000_add_claims.sql (44.35ms)20432026/09/20 19:22:25 OK 20260920000000_drop_claims.sql (34.17ms)20442026/09/20 19:22:25 goose: successfully migrated database to version: 2026092000000020452026/09/20 19:22:25 OK 1_commit_pending_closure.sql (1.33ms)20462026/09/20 19:22:25 OK 2_object_stats_trigger.sql (277.83µs)20472026/09/20 19:22:25 goose: up to current file version: 220482026-09-20 19:22:25.554 UTC [84885] ERROR: relation "goose_db_version" does not exist at character 3620492026-09-20 19:22:25.554 UTC [84885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20502026/09/20 19:22:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.613949ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20512026/09/20 19:22:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20522026/09/20 19:22:25 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWNiM2MwMzYtNWQzNy00ODY3LWJiYTgtMTY0ZjJkYWQ0YzIxLmY3MmFjNjA3LTM0Y2YtNGE0ZC1hYTM5LWM3N2FlZDdhODdkYngxNzg5OTMyMTQzNTk2MDEyMDAw parts=1220532026/09/20 19:22:25 INFO Received uploads request method=POST path=/api/pending_closures2054--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.24s)20552026/09/20 19:22:25 OK 20241026095416_initial_model.sql (172.55ms)20562026/09/20 19:22:25 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)20572026/09/20 19:22:25 OK 20251218171726_add_pins.sql (4.39ms)20582026/09/20 19:22:25 INFO Aborted multipart uploads count=020592026/09/20 19:22:25 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)20602026/09/20 19:22:25 WARN Force mode enabled - objects will be deleted immediately without grace period20612026/09/20 19:22:25 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=020622026/09/20 19:22:25 INFO Vacuumed table table=pending_closures20632026/09/20 19:22:25 INFO Vacuumed table table=pending_objects20642026/09/20 19:22:25 INFO Vacuumed table table=multipart_uploads20652026/09/20 19:22:25 OK 20260905000000_add_claims.sql (5.28ms)20662026/09/20 19:22:25 INFO Vacuumed table table=closures20672026/09/20 19:22:25 INFO Vacuumed table table=objects2068--- PASS: TestGCMetrics (3.09s)20692026/09/20 19:22:25 OK 20260920000000_drop_claims.sql (2.12ms)20702026/09/20 19:22:25 goose: successfully migrated database to version: 2026092000000020712026/09/20 19:22:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.739234ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20722026/09/20 19:22:25 OK 1_commit_pending_closure.sql (2.4ms)20732026/09/20 19:22:25 OK 2_object_stats_trigger.sql (490.75µs)20742026/09/20 19:22:25 goose: up to current file version: 220752026-09-20 19:22:25.835 UTC [84888] ERROR: relation "goose_db_version" does not exist at character 3620762026-09-20 19:22:25.835 UTC [84888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20772026/09/20 19:22:25 OK 20241026095416_initial_model.sql (65.2ms)20782026/09/20 19:22:25 OK 20251210153512_drop_unused_gin_index.sql (8.44ms)20792026/09/20 19:22:25 OK 20251218171726_add_pins.sql (26.92ms)20802026/09/20 19:22:25 OK 20260628120000_add_object_size_and_stats.sql (29.91ms)20812026/09/20 19:22:26 OK 20260905000000_add_claims.sql (22.72ms)20822026/09/20 19:22:26 OK 20260920000000_drop_claims.sql (4.35ms)20832026/09/20 19:22:26 goose: successfully migrated database to version: 2026092000000020842026/09/20 19:22:26 OK 1_commit_pending_closure.sql (7.02ms)20852026/09/20 19:22:26 OK 2_object_stats_trigger.sql (2.26ms)20862026/09/20 19:22:26 goose: up to current file version: 220872026-09-20 19:22:26.026 UTC [84889] ERROR: relation "goose_db_version" does not exist at character 3620882026-09-20 19:22:26.026 UTC [84889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20892026/09/20 19:22:26 OK 20241026095416_initial_model.sql (86.32ms)20902026/09/20 19:22:26 OK 20251210153512_drop_unused_gin_index.sql (10.01ms)20912026/09/20 19:22:26 OK 20251218171726_add_pins.sql (32.17ms)20922026/09/20 19:22:26 OK 20260628120000_add_object_size_and_stats.sql (29.84ms)20932026/09/20 19:22:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=818.04796ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2094--- PASS: TestGCBugBareHashReferences (3.07s)20952026/09/20 19:22:26 OK 20260905000000_add_claims.sql (53.66ms)20962026/09/20 19:22:26 OK 20260920000000_drop_claims.sql (43.12ms)20972026/09/20 19:22:26 goose: successfully migrated database to version: 2026092000000020982026/09/20 19:22:26 INFO lead: acquired remote=192.0.2.1:123420992026/09/20 19:22:26 OK 1_commit_pending_closure.sql (7.29ms)21002026/09/20 19:22:26 OK 2_object_stats_trigger.sql (1.13ms)21012026/09/20 19:22:26 goose: up to current file version: 22102=== NAME TestOrphanedObjectsGCStressTest2103 orphaned_objects_gc_test.go:509: Stress test completed successfully:2104 orphaned_objects_gc_test.go:510: - Active objects preserved: 202105 orphaned_objects_gc_test.go:511: - Objects deleted: 2102106 orphaned_objects_gc_test.go:512: - Total GC'd: 2102107--- PASS: TestOrphanedObjectsGCStressTest (8.22s)21082026-09-20 19:22:26.381 UTC [84891] ERROR: relation "goose_db_version" does not exist at character 3621092026-09-20 19:22:26.381 UTC [84891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21102026-09-20 19:22:26.408 UTC [84892] ERROR: relation "goose_db_version" does not exist at character 3621112026-09-20 19:22:26.408 UTC [84892] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21122026/09/20 19:22:26 OK 20241026095416_initial_model.sql (70.1ms)21132026/09/20 19:22:26 INFO lead: released remote=192.0.2.1:123421142026/09/20 19:22:26 OK 20251210153512_drop_unused_gin_index.sql (6.25ms)21152026/09/20 19:22:26 OK 20251218171726_add_pins.sql (3.81ms)21162026/09/20 19:22:26 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)21172026/09/20 19:22:26 OK 20241026095416_initial_model.sql (45.84ms)21182026/09/20 19:22:26 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)21192026/09/20 19:22:26 OK 20260905000000_add_claims.sql (3.78ms)21202026/09/20 19:22:26 OK 20260920000000_drop_claims.sql (1.74ms)21212026/09/20 19:22:26 goose: successfully migrated database to version: 2026092000000021222026/09/20 19:22:26 OK 20251218171726_add_pins.sql (2.55ms)21232026/09/20 19:22:26 OK 1_commit_pending_closure.sql (2.26ms)21242026/09/20 19:22:26 OK 20260628120000_add_object_size_and_stats.sql (2.5ms)21252026/09/20 19:22:26 OK 2_object_stats_trigger.sql (574.63µs)21262026/09/20 19:22:26 goose: up to current file version: 221272026/09/20 19:22:26 OK 20260905000000_add_claims.sql (3.03ms)21282026/09/20 19:22:26 OK 20260920000000_drop_claims.sql (3.1ms)21292026/09/20 19:22:26 goose: successfully migrated database to version: 2026092000000021302026/09/20 19:22:26 OK 1_commit_pending_closure.sql (1.97ms)21312026/09/20 19:22:26 OK 2_object_stats_trigger.sql (510.21µs)21322026/09/20 19:22:26 goose: up to current file version: 221332026/09/20 19:22:26 INFO lead: acquired remote=192.0.2.1:123421342026/09/20 19:22:26 INFO lead: released remote=192.0.2.1:12342135--- PASS: TestLeadElectsOneAndHandsOver (2.59s)2136=== NAME TestPinProtectsFromGC2137 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-84476-2894457087/TestPinProtectsFromGC1788669494/001/store/nkc31n4dl8ksg9fdjqp4bcw3q57w92h3-pinned-file.txt2138 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-84476-2894457087/TestPinProtectsFromGC1788669494/001/store/dn8gcwnc3p8q7792sm327iap7vvpl3g5-unpinned-file.txt21392026/09/20 19:22:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21402026/09/20 19:22:26 INFO Received uploads request method=POST path=/api/pending_closures21412026/09/20 19:22:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21422026/09/20 19:22:26 INFO Uploading nkc31n4dl8ksg9fdjqp4bcw3q57w92h3-pinned-file.txt (128B)21432026/09/20 19:22:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21442026/09/20 19:22:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21452026/09/20 19:22:26 INFO Signed narinfos id=1 count=121462026/09/20 19:22:26 INFO Uploading 1 narinfos21472026/09/20 19:22:26 WARN Failed to register uploaded object key=nkc31n4dl8ksg9fdjqp4bcw3q57w92h3.ls error="server returned 404: 404 page not found\n"21482026/09/20 19:22:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21492026/09/20 19:22:26 WARN Failed to register uploaded object key=nkc31n4dl8ksg9fdjqp4bcw3q57w92h3.narinfo error="server returned 404: 404 page not found\n"21502026/09/20 19:22:26 INFO Completed upload id=121512026/09/20 19:22:26 INFO Upload complete. (68ms)21522026/09/20 19:22:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21532026/09/20 19:22:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21542026/09/20 19:22:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21552026/09/20 19:22:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21562026/09/20 19:22:26 INFO Received uploads request method=POST path=/api/pending_closures21572026/09/20 19:22:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21582026/09/20 19:22:26 INFO Uploading dn8gcwnc3p8q7792sm327iap7vvpl3g5-unpinned-file.txt (128B)21592026/09/20 19:22:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21602026/09/20 19:22:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21612026/09/20 19:22:26 INFO Signed narinfos id=2 count=121622026/09/20 19:22:26 INFO Uploading 1 narinfos21632026/09/20 19:22:26 WARN Failed to register uploaded object key=dn8gcwnc3p8q7792sm327iap7vvpl3g5.ls error="server returned 404: 404 page not found\n"21642026/09/20 19:22:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21652026/09/20 19:22:26 WARN Failed to register uploaded object key=dn8gcwnc3p8q7792sm327iap7vvpl3g5.narinfo error="server returned 404: 404 page not found\n"21662026/09/20 19:22:26 INFO Completed upload id=221672026/09/20 19:22:26 INFO Upload complete. (64ms)21682026/09/20 19:22:26 INFO Received create pin request method=POST path=/api/pins/myapp21692026/09/20 19:22:26 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-84476-2894457087/TestPinProtectsFromGC1788669494/001/store/nkc31n4dl8ksg9fdjqp4bcw3q57w92h3-pinned-file.txt narinfo_key=nkc31n4dl8ksg9fdjqp4bcw3q57w92h3.narinfo21702026/09/20 19:22:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures21712026/09/20 19:22:26 INFO Garbage collection started21722026/09/20 19:22:26 INFO Aborted multipart uploads count=021732026/09/20 19:22:26 WARN Force mode enabled - objects will be deleted immediately without grace period21742026/09/20 19:22:27 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=021752026/09/20 19:22:27 INFO Vacuumed table table=pending_closures21762026/09/20 19:22:27 INFO Vacuumed table table=pending_objects21772026/09/20 19:22:27 INFO Vacuumed table table=multipart_uploads21782026/09/20 19:22:27 INFO Vacuumed table table=closures21792026/09/20 19:22:27 INFO Vacuumed table table=objects21802026/09/20 19:22:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.715539523s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21812026/09/20 19:22:28 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-config21822026/09/20 19:22:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02183 client_integration_test.go:794: Pin successfully protected closure from garbage collection2184--- PASS: TestPinProtectsFromGC (4.53s)21852026/09/20 19:22:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.200695ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21862026/09/20 19:22:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=375.593692ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21872026/09/20 19:22:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.582722ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21882026/09/20 19:22:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.498127925s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21892026/09/20 19:22:31 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"21902026/09/20 19:22:31 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_closures21912026/09/20 19:22:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.104056ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21922026/09/20 19:22:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.266699ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21932026/09/20 19:22:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=863.348499ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21942026/09/20 19:22:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.519649323s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2195--- PASS: TestClientErrorHandling (0.00s)2196 --- PASS: TestClientErrorHandling/InvalidStorePath (1.54s)2197 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.44s)2198 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.93s)2199PASS2200{"timestamp":"2026-09-20T19:22:35.082236Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59613","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(9)"}22012026-09-20 19:22:35.176 UTC [84555] LOG: received smart shutdown request22022026-09-20 19:22:35.177 UTC [84555] LOG: background worker "logical replication launcher" (PID 84565) exited with exit code 122032026-09-20 19:22:35.184 UTC [84560] LOG: shutting down22042026-09-20 19:22:35.184 UTC [84560] LOG: checkpoint starting: shutdown immediate22052026-09-20 19:22:36.304 UTC [84560] LOG: checkpoint complete: wrote 13053 buffers (79.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.775 s, sync=0.308 s, total=1.120 s; sync files=18404, longest=0.001 s, average=0.001 s; distance=255510 kB, estimate=255510 kB; lsn=0/111128F0, redo lsn=0/111128F022062026-09-20 19:22:36.309 UTC [84555] LOG: database system is shut down2207Running OIDC tests...2208=== RUN TestGlobMatch2209=== PAUSE TestGlobMatch2210=== RUN TestAudienceForIssuer2211=== PAUSE TestAudienceForIssuer2212=== RUN TestValidateToken_ValidToken2213=== PAUSE TestValidateToken_ValidToken2214=== RUN TestValidateToken_WrongAudience2215=== PAUSE TestValidateToken_WrongAudience2216=== RUN TestValidateToken_Expired2217=== PAUSE TestValidateToken_Expired2218=== RUN TestValidateToken_BoundClaimsMismatch2219=== PAUSE TestValidateToken_BoundClaimsMismatch2220=== RUN TestValidateToken_BoundSubjectMismatch2221=== PAUSE TestValidateToken_BoundSubjectMismatch2222=== RUN TestValidateToken_MultipleProviders2223=== PAUSE TestValidateToken_MultipleProviders2224=== RUN TestValidateToken_NoMatchingProvider2225=== PAUSE TestValidateToken_NoMatchingProvider2226=== RUN TestValidateToken_KubernetesServiceAccount2227=== PAUSE TestValidateToken_KubernetesServiceAccount2228=== RUN TestNewValidator_KubernetesRequiresCA2229=== PAUSE TestNewValidator_KubernetesRequiresCA2230=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2231=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2232=== RUN TestScopes_LegacyProviderDefaultsToWrite2233=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2234=== RUN TestScopes_Rules2235=== PAUSE TestScopes_Rules2236=== RUN TestScopes_ConfigValidation2237=== PAUSE TestScopes_ConfigValidation2238=== CONT TestGlobMatch2239=== RUN TestGlobMatch/foo_foo2240=== PAUSE TestGlobMatch/foo_foo2241=== RUN TestGlobMatch/foo_bar2242=== PAUSE TestGlobMatch/foo_bar2243=== CONT TestScopes_LegacyProviderDefaultsToWrite2244=== CONT TestValidateToken_NoMatchingProvider2245=== RUN TestGlobMatch/*_2246=== PAUSE TestGlobMatch/*_2247=== RUN TestGlobMatch/*_anything2248=== PAUSE TestGlobMatch/*_anything2249=== RUN TestGlobMatch/foo*_foo2250=== PAUSE TestGlobMatch/foo*_foo2251=== RUN TestGlobMatch/foo*_foobar2252=== PAUSE TestGlobMatch/foo*_foobar2253=== RUN TestGlobMatch/foo*_bar2254=== PAUSE TestGlobMatch/foo*_bar2255=== RUN TestGlobMatch/*bar_bar2256=== PAUSE TestGlobMatch/*bar_bar2257=== RUN TestGlobMatch/*bar_foobar2258=== PAUSE TestGlobMatch/*bar_foobar2259=== RUN TestGlobMatch/*bar_foo2260=== PAUSE TestGlobMatch/*bar_foo2261=== RUN TestGlobMatch/foo*bar_foobar2262=== PAUSE TestGlobMatch/foo*bar_foobar2263=== RUN TestGlobMatch/foo*bar_foo123bar2264=== CONT TestValidateToken_WrongAudience2265=== CONT TestValidateToken_ValidToken2266=== CONT TestAudienceForIssuer2267--- PASS: TestAudienceForIssuer (0.00s)2268=== CONT TestNewValidator_KubernetesRequiresCA2269=== CONT TestValidateToken_BoundSubjectMismatch2270=== CONT TestValidateToken_MultipleProviders2271=== CONT TestScopes_ConfigValidation2272=== CONT TestValidateToken_BoundClaimsMismatch2273=== PAUSE TestGlobMatch/foo*bar_foo123bar2274=== RUN TestGlobMatch/foo*bar_foobarbaz2275=== PAUSE TestGlobMatch/foo*bar_foobarbaz2276=== RUN TestGlobMatch/*/*_foo/bar2277=== PAUSE TestGlobMatch/*/*_foo/bar2278=== RUN TestGlobMatch/*/*_foo2279=== PAUSE TestGlobMatch/*/*_foo2280=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2281=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2282=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02283=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02284=== RUN TestGlobMatch/refs/*/main_refs/heads/main2285=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2286=== RUN TestGlobMatch/fo?_foo2287=== PAUSE TestGlobMatch/fo?_foo2288=== RUN TestGlobMatch/fo?_fo2289=== PAUSE TestGlobMatch/fo?_fo2290=== RUN TestGlobMatch/fo?_fooo2291=== PAUSE TestGlobMatch/fo?_fooo2292=== RUN TestGlobMatch/?oo_foo2293=== PAUSE TestGlobMatch/?oo_foo2294=== RUN TestGlobMatch/?oo_boo2295=== PAUSE TestGlobMatch/?oo_boo2296=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2297=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2298=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2299=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2300=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23012026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59779/oidc23022026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59775/oidc23032026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59782/oidc23042026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59777/oidc23052026/09/20 19:22:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59776/oidc23062026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59783/oidc2307--- PASS: TestScopes_ConfigValidation (0.00s)2308=== CONT TestScopes_Rules23092026/09/20 19:22:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59778/oidc23102026/09/20 19:22:37 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59781/oidc23112026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59794/oidc23122026/09/20 19:22:37 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232313--- PASS: TestValidateToken_WrongAudience (0.01s)2314=== CONT TestValidateToken_KubernetesServiceAccount2315--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2316--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2317--- PASS: TestValidateToken_ValidToken (0.01s)2318=== CONT TestGlobMatch/*/*_foo/bar2319--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2320=== CONT TestGlobMatch/foo_foo2321=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2322=== CONT TestGlobMatch/?oo_boo2323=== CONT TestGlobMatch/?oo_foo2324=== CONT TestGlobMatch/fo?_fo2325=== CONT TestGlobMatch/fo?_foo2326=== CONT TestGlobMatch/refs/*/main_refs/heads/main2327=== CONT TestGlobMatch/fo?_fooo2328--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2329=== CONT TestValidateToken_Expired2330=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2331=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02332=== CONT TestGlobMatch/foo*bar_foobarbaz2333=== CONT TestGlobMatch/foo*bar_foo123bar2334=== CONT TestGlobMatch/foo*bar_foobar2335=== CONT TestGlobMatch/*/*_foo2336=== CONT TestGlobMatch/*bar_foobar2337=== CONT TestGlobMatch/foo*_foo2338=== CONT TestGlobMatch/foo*_bar2339=== CONT TestGlobMatch/foo*_foobar2340=== CONT TestGlobMatch/*_2341=== CONT TestGlobMatch/foo_bar2342=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2343=== CONT TestGlobMatch/*bar_bar2344--- PASS: TestValidateToken_MultipleProviders (0.01s)2345=== CONT TestGlobMatch/*_anything2346=== CONT TestGlobMatch/*bar_foo2347--- PASS: TestGlobMatch (0.00s)2348 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2349 --- PASS: TestGlobMatch/foo_foo (0.00s)2350 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2351 --- PASS: TestGlobMatch/?oo_foo (0.00s)2352 --- PASS: TestGlobMatch/fo?_fo (0.00s)2353 --- PASS: TestGlobMatch/fo?_foo (0.00s)2354 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2355 --- PASS: TestGlobMatch/?oo_boo (0.00s)2356 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2357 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2358 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2359 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2360 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2361 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2362 --- PASS: TestGlobMatch/*/*_foo (0.00s)2363 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2364 --- PASS: TestGlobMatch/foo*_foo (0.00s)2365 --- PASS: TestGlobMatch/foo*_bar (0.00s)2366 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2367 --- PASS: TestGlobMatch/*_ (0.00s)2368 --- PASS: TestGlobMatch/foo_bar (0.00s)2369 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2370 --- PASS: TestGlobMatch/*bar_bar (0.00s)2371 --- PASS: TestGlobMatch/*_anything (0.00s)2372 --- PASS: TestGlobMatch/*bar_foo (0.00s)23732026/09/20 19:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59798/oidc2374--- PASS: TestValidateToken_Expired (0.00s)23752026/09/20 19:22:37 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:597972376--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)23772026/09/20 19:22:37 http: TLS handshake error from 127.0.0.1:59785: remote error: tls: bad certificate2378--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2379--- PASS: TestScopes_Rules (0.01s)2380--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2381PASS2382Running hook tests...2383=== RUN TestSendPathsEmpty2384=== PAUSE TestSendPathsEmpty2385=== RUN TestQueueEnqueueAndFetch2386=== PAUSE TestQueueEnqueueAndFetch2387=== RUN TestQueueDeduplication2388=== PAUSE TestQueueDeduplication2389=== RUN TestQueueRemove2390=== PAUSE TestQueueRemove2391=== RUN TestQueueFetchBatchLimit2392=== PAUSE TestQueueFetchBatchLimit2393=== RUN TestQueueRetryMovesToBack2394=== PAUSE TestQueueRetryMovesToBack2395=== RUN TestQueueFetchRemoveLifecycle2396=== PAUSE TestQueueFetchRemoveLifecycle2397=== RUN TestQueueConcurrentWriters2398=== PAUSE TestQueueConcurrentWriters2399=== RUN TestQueueRemoveLargeClosure2400=== PAUSE TestQueueRemoveLargeClosure2401=== RUN TestServerClientIntegration2402=== PAUSE TestServerClientIntegration2403=== RUN TestServerQueueError2404=== PAUSE TestServerQueueError2405=== RUN TestGetListenerSocketActivation2406 server_test.go:210: === RUN TestGetListenerSocketActivation2407 --- PASS: TestGetListenerSocketActivation (0.00s)2408 PASS2409 2410--- PASS: TestGetListenerSocketActivation (0.01s)2411=== RUN TestDrainIsolatesPoisonPath2412=== PAUSE TestDrainIsolatesPoisonPath2413=== RUN TestRunNotBlockedByPoisonHead2414=== PAUSE TestRunNotBlockedByPoisonHead2415=== RUN TestDrainGivesUpWhenServerDown2416=== PAUSE TestDrainGivesUpWhenServerDown2417=== RUN TestFailedPathPrunedByLaterClosure2418=== PAUSE TestFailedPathPrunedByLaterClosure2419=== RUN TestWorkerUploadsAndRemoves2420=== PAUSE TestWorkerUploadsAndRemoves2421=== RUN TestWorkerSkipsGCdPaths2422=== PAUSE TestWorkerSkipsGCdPaths2423=== RUN TestWorkerPrunesClosureDeps2424=== PAUSE TestWorkerPrunesClosureDeps2425=== RUN TestDrainTimeout2426=== PAUSE TestDrainTimeout2427=== CONT TestSendPathsEmpty2428=== CONT TestServerQueueError2429--- PASS: TestSendPathsEmpty (0.00s)2430=== CONT TestWorkerUploadsAndRemoves2431=== CONT TestQueueFetchRemoveLifecycle2432=== CONT TestDrainGivesUpWhenServerDown2433=== CONT TestQueueRemove2434=== CONT TestRunNotBlockedByPoisonHead2435=== CONT TestWorkerPrunesClosureDeps2436=== CONT TestServerClientIntegration2437=== CONT TestQueueRemoveLargeClosure2438=== CONT TestQueueConcurrentWriters24392026/09/20 19:22:37 ERROR Failed to queue paths error="permission denied" count=12440--- PASS: TestServerQueueError (0.00s)2441=== CONT TestDrainIsolatesPoisonPath2442--- PASS: TestServerClientIntegration (0.00s)2443=== CONT TestQueueRetryMovesToBack24442026/09/20 19:22:37 INFO Upload queue status pending=324452026/09/20 19:22:37 INFO Uploading batch count=124462026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=12447--- PASS: TestQueueRemove (0.01s)2448=== CONT TestDrainTimeout24492026/09/20 19:22:37 INFO Upload queue status pending=224502026/09/20 19:22:37 INFO Upload queue status pending=224512026/09/20 19:22:37 INFO Uploading batch count=424522026/09/20 19:22:37 INFO Uploading batch count=224532026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=424542026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=224552026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainGivesUpWhenServerDown2968536015/002/a24562026/09/20 19:22:37 INFO Uploading batch count=224572026/09/20 19:22:37 INFO Uploading batch count=124582026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainGivesUpWhenServerDown2968536015/002/b2459--- PASS: TestQueueRetryMovesToBack (0.01s)2460=== CONT TestQueueDeduplication24612026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainIsolatesPoisonPath1443267777/002/bbb24622026/09/20 19:22:37 INFO Uploading batch count=224632026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=224642026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainGivesUpWhenServerDown2968536015/002/c2465--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2466=== CONT TestFailedPathPrunedByLaterClosure24672026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainGivesUpWhenServerDown2968536015/002/d24682026/09/20 19:22:37 INFO Uploading batch count=124692026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=124702026/09/20 19:22:37 INFO Uploading batch count=224712026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=224722026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainGivesUpWhenServerDown2968536015/002/e24732026/09/20 19:22:37 INFO Uploading batch count=124742026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=124752026/09/20 19:22:37 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-84476-2894457087/TestDrainGivesUpWhenServerDown2968536015/002/f24762026/09/20 19:22:37 INFO Uploading batch count=124772026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=124782026/09/20 19:22:37 ERROR Drain finished with paths left in queue remaining=1024792026/09/20 19:22:37 ERROR Drain finished with paths left in queue remaining=124802026/09/20 19:22:37 INFO Uploading batch count=22481--- PASS: TestDrainIsolatesPoisonPath (0.01s)2482=== CONT TestQueueFetchBatchLimit24832026/09/20 19:22:37 INFO Uploading batch count=124842026/09/20 19:22:37 ERROR Upload failed error="upload failed" count=12485--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2486=== CONT TestWorkerSkipsGCdPaths2487--- PASS: TestQueueDeduplication (0.00s)2488=== CONT TestQueueEnqueueAndFetch24892026/09/20 19:22:37 INFO Uploading batch count=124902026/09/20 19:22:37 INFO Uploading batch count=12491--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)24922026/09/20 19:22:37 INFO Upload queue status pending=224932026/09/20 19:22:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-84476-2894457087/TestWorkerSkipsGCdPaths3547059720/002/nonexistent2494--- PASS: TestQueueFetchBatchLimit (0.00s)24952026/09/20 19:22:37 INFO Uploading batch count=12496--- PASS: TestQueueEnqueueAndFetch (0.00s)2497--- PASS: TestWorkerPrunesClosureDeps (0.03s)2498--- PASS: TestWorkerUploadsAndRemoves (0.03s)2499--- PASS: TestWorkerSkipsGCdPaths (0.02s)2500--- PASS: TestQueueRemoveLargeClosure (0.06s)2501--- PASS: TestQueueConcurrentWriters (0.15s)25022026/09/20 19:22:37 ERROR Upload failed error="context deadline exceeded" count=225032026/09/20 19:22:37 ERROR Drain finished with paths left in queue remaining=42504--- PASS: TestDrainTimeout (0.21s)25052026/09/20 19:22:38 INFO Uploading batch count=125062026/09/20 19:22:38 INFO Uploading batch count=125072026/09/20 19:22:38 INFO Uploading batch count=125082026/09/20 19:22:38 ERROR Upload failed error="upload failed" count=125092026/09/20 19:22:38 INFO Uploading batch count=125102026/09/20 19:22:38 ERROR Upload failed error="upload failed" count=125112026/09/20 19:22:38 INFO Uploading batch count=125122026/09/20 19:22:38 ERROR Upload failed error="upload failed" count=125132026/09/20 19:22:38 INFO Uploading batch count=125142026/09/20 19:22:38 ERROR Upload failed error="upload failed" count=125152026/09/20 19:22:38 ERROR Drain finished with paths left in queue remaining=12516--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2517PASS