niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #188
· raw
1Running client tests...2=== RUN TestDumpPathCaseHackMatchesNix3=== RUN TestDumpPathCaseHackMatchesNix/numbered_case_variants4=== RUN TestDumpPathCaseHackMatchesNix/restored_name_ordering5--- PASS: TestDumpPathCaseHackMatchesNix (7.61s)6 --- PASS: TestDumpPathCaseHackMatchesNix/numbered_case_variants (7.57s)7 --- PASS: TestDumpPathCaseHackMatchesNix/restored_name_ordering (0.04s)8=== RUN TestDumpPathCaseHackCollisionMatchesNix9--- PASS: TestDumpPathCaseHackCollisionMatchesNix (0.05s)10=== RUN TestDoServerRequestAttachesToken11=== PAUSE TestDoServerRequestAttachesToken12=== RUN TestCaseHackSuffix13=== PAUSE TestCaseHackSuffix14=== RUN TestFilterOversizedClosures15=== PAUSE TestFilterOversizedClosures16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== 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 TestSetClientTLS55=== PAUSE TestSetClientTLS56=== RUN TestSetClientTLSDoesNotMutateDefaultTransport57=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport58=== RUN TestSetClientTLSErrors59=== PAUSE TestSetClientTLSErrors60=== RUN TestStaticToken61=== PAUSE TestStaticToken62=== RUN TestFileTokenReadsAndCaches63=== PAUSE TestFileTokenReadsAndCaches64=== RUN TestFileTokenMissing65=== PAUSE TestFileTokenMissing66=== RUN TestFileTokenEmpty67=== PAUSE TestFileTokenEmpty68=== RUN TestScriptTokenNoExpiryRerunsEveryCall69=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall70=== RUN TestScriptTokenCachesUntilRefresh71=== PAUSE TestScriptTokenCachesUntilRefresh72=== RUN TestScriptTokenEmptyToken73=== PAUSE TestScriptTokenEmptyToken74=== RUN TestScriptTokenBadJSON75=== PAUSE TestScriptTokenBadJSON76=== RUN TestScriptTokenScriptFails77=== PAUSE TestScriptTokenScriptFails78=== RUN TestScriptTokenEmptyCommand79=== PAUSE TestScriptTokenEmptyCommand80=== CONT TestDoServerRequestAttachesToken81=== CONT TestResolveStorePath82=== CONT TestScriptTokenEmptyCommand83=== CONT TestFileTokenMissing84=== CONT TestScriptTokenEmptyToken85=== CONT TestScriptTokenScriptFails86=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess872026/09/10 03:42:33 WARN Rate limiter enabled after throttle name=server-test rate=588=== CONT TestScriptTokenBadJSON89=== CONT TestScriptTokenNoExpiryRerunsEveryCall90=== CONT TestScriptTokenCachesUntilRefresh91=== CONT TestFileTokenEmpty92--- PASS: TestScriptTokenEmptyCommand (0.00s)93--- PASS: TestFileTokenMissing (0.00s)94=== CONT TestEncodeNixBase32WithRealHash95--- PASS: TestEncodeNixBase32WithRealHash (0.00s)96=== CONT TestRateLimiterFeedback97=== RUN TestRateLimiterFeedback/429_enables_limiter98=== PAUSE TestRateLimiterFeedback/429_enables_limiter99=== RUN TestRateLimiterFeedback/503_enables_limiter100=== PAUSE TestRateLimiterFeedback/503_enables_limiter101=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter102=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter103=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter104=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter105=== CONT TestPathInfoCACompatibility106=== RUN TestPathInfoCACompatibility/null_ca_field107=== PAUSE TestPathInfoCACompatibility/null_ca_field108=== RUN TestPathInfoCACompatibility/old_string_format_-_text109=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text110=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive111=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive112=== RUN TestPathInfoCACompatibility/new_structured_format_-_text113=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text114=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method115=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method116--- PASS: TestResolveStorePath (0.00s)117=== CONT TestParsePathInfoJSON118=== RUN TestParsePathInfoJSON/Nix_format119=== PAUSE TestParsePathInfoJSON/Nix_format120=== RUN TestParsePathInfoJSON/Lix_format121=== PAUSE TestParsePathInfoJSON/Lix_format122=== RUN TestParsePathInfoJSON/empty_input123=== CONT TestParsePathInfoJSONMultiplePaths124=== PAUSE TestParsePathInfoJSON/empty_input125=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths127=== RUN TestParsePathInfoJSON/whitespace_only128=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths129=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths130=== CONT TestPathInfoHashCompatibility131=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)132=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)133=== PAUSE TestParsePathInfoJSON/whitespace_only134=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon135=== RUN TestParsePathInfoJSON/invalid_JSON136=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon137=== PAUSE TestParsePathInfoJSON/invalid_JSON138=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI139=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI140=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512141=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512142=== CONT TestGetStorePathHash143=== RUN TestGetStorePathHash/valid_store_path144=== CONT TestConvertHashToNix32145=== PAUSE TestGetStorePathHash/valid_store_path146=== RUN TestGetStorePathHash/basename_without_hyphen_should_error147=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error148=== RUN TestConvertHashToNix32/SRI_format_to_Nix32149=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error150=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error151=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32152=== RUN TestConvertHashToNix32/already_Nix32_format153=== PAUSE TestConvertHashToNix32/already_Nix32_format154=== RUN TestConvertHashToNix32/invalid_format155--- PASS: TestFileTokenEmpty (0.00s)156=== PAUSE TestConvertHashToNix32/invalid_format157=== CONT TestDumpPathMatchesNix158=== CONT TestEncodeNixBase32159=== RUN TestEncodeNixBase32/test_string_hash160--- PASS: TestDoServerRequestAttachesToken (0.00s)161=== CONT TestDumpPathWriterError162=== PAUSE TestEncodeNixBase32/test_string_hash163=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error164=== RUN TestEncodeNixBase32/empty_input165=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error166=== PAUSE TestEncodeNixBase32/empty_input167=== CONT TestDumpPathSingleFile168=== CONT TestSetClientTLSDoesNotMutateDefaultTransport169--- PASS: TestScriptTokenScriptFails (0.01s)170=== CONT TestFileTokenReadsAndCaches171--- PASS: TestFileTokenReadsAndCaches (0.00s)172=== CONT TestStaticToken173--- PASS: TestStaticToken (0.00s)174=== CONT TestSetClientTLSErrors175--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)176=== CONT TestPartSizeForNAR177=== RUN TestPartSizeForNAR/zero_stays_at_minimum178=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum179=== RUN TestPartSizeForNAR/small_stays_at_minimum180=== PAUSE TestPartSizeForNAR/small_stays_at_minimum181=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum182=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum183=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts184=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts185=== RUN TestPartSizeForNAR/1_TiB186=== PAUSE TestPartSizeForNAR/1_TiB187=== RUN TestPartSizeForNAR/5_TiB_S3_max_object188=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object189=== RUN TestPartSizeForNAR/capped_at_5_GiB190=== PAUSE TestPartSizeForNAR/capped_at_5_GiB191=== CONT TestUploadMultipart_SupersededByPeer192=== RUN TestUploadMultipart_SupersededByPeer/exists193=== PAUSE TestUploadMultipart_SupersededByPeer/exists194=== RUN TestUploadMultipart_SupersededByPeer/missing195=== PAUSE TestUploadMultipart_SupersededByPeer/missing196=== CONT TestShellSplitErrors197--- PASS: TestShellSplitErrors (0.00s)198=== CONT TestSetClientTLS199--- PASS: TestScriptTokenBadJSON (0.01s)200=== CONT TestShellSplit201--- PASS: TestShellSplit (0.00s)202=== CONT TestDoWithRetry_BodyReplayedViaGetBody203=== RUN TestSetClientTLSErrors/missing_cert_file204=== PAUSE TestSetClientTLSErrors/missing_cert_file205=== RUN TestSetClientTLSErrors/missing_key_file206=== PAUSE TestSetClientTLSErrors/missing_key_file207=== RUN TestSetClientTLSErrors/missing_ca_file208=== PAUSE TestSetClientTLSErrors/missing_ca_file209=== RUN TestSetClientTLSErrors/invalid_ca_file210=== PAUSE TestSetClientTLSErrors/invalid_ca_file211=== CONT TestFilterOversizedClosures212=== RUN TestFilterOversizedClosures/no_limit_keeps_everything213=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything214=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped215=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped216=== RUN TestFilterOversizedClosures/all_closures_skipped217=== PAUSE TestFilterOversizedClosures/all_closures_skipped218=== CONT TestCaseHackSuffix2192026/09/10 03:42:33 WARN Rate limiter enabled after throttle name=server-test rate=52202026/09/10 03:42:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:633632212026/09/10 03:42:33 WARN Rate limiter backed off name=server-test rate=52222026/09/10 03:42:33 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:63363223--- PASS: TestScriptTokenEmptyToken (0.01s)224=== CONT TestRateLimiterFeedback/429_enables_limiter225--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)226=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2272026/09/10 03:42:33 WARN Rate limiter enabled after throttle name=server-test rate=52282026/09/10 03:42:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:633652292026/09/10 03:42:33 WARN Rate limiter backed off name=server-test rate=5230=== CONT TestRateLimiterFeedback/503_enables_limiter231=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter232=== RUN TestSetClientTLS/rejects_connection_without_client_cert233=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert234=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA235=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA236=== RUN TestSetClientTLS/preserves_debug_logging_transport237=== PAUSE TestSetClientTLS/preserves_debug_logging_transport238=== CONT TestPathInfoCACompatibility/null_ca_field239=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method240=== CONT TestPathInfoCACompatibility/new_structured_format_-_text241=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive242=== CONT TestPathInfoCACompatibility/old_string_format_-_text243--- PASS: TestPathInfoCACompatibility (0.00s)244 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)245 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)246 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)247 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)248 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)249=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2502026/09/10 03:42:33 WARN Rate limiter enabled after throttle name=server-test rate=5251=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2522026/09/10 03:42:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:63370253--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)254 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)255 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)256=== CONT TestParsePathInfoJSON/Nix_format257=== CONT TestParsePathInfoJSON/whitespace_only258=== CONT TestParsePathInfoJSON/invalid_JSON259=== CONT TestParsePathInfoJSON/empty_input260=== CONT TestParsePathInfoJSON/Lix_format261--- PASS: TestParsePathInfoJSON (0.00s)262 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)263 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)264 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)265 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)266 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)267=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)268=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122692026/09/10 03:42:33 WARN Rate limiter backed off name=server-test rate=5270=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon271=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI272=== CONT TestConvertHashToNix32/SRI_format_to_Nix32273=== CONT TestConvertHashToNix32/already_Nix32_format274=== CONT TestConvertHashToNix32/invalid_format275=== CONT TestGetStorePathHash/valid_store_path276=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error277=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error278=== CONT TestGetStorePathHash/basename_without_hyphen_should_error279=== CONT TestEncodeNixBase32/test_string_hash280=== CONT TestUploadMultipart_SupersededByPeer/exists281=== CONT TestEncodeNixBase32/empty_input282--- PASS: TestPathInfoHashCompatibility (0.00s)283 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)284 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)285 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)286 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)287=== CONT TestPartSizeForNAR/zero_stays_at_minimum288--- PASS: TestConvertHashToNix32 (0.00s)289 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)290 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)291 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)292--- PASS: TestRateLimiterFeedback (0.00s)293 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)294 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)295 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)296 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)297=== CONT TestPartSizeForNAR/5_TiB_S3_max_object298=== CONT TestPartSizeForNAR/1_TiB299=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts300=== CONT TestPartSizeForNAR/capped_at_5_GiB301--- PASS: TestEncodeNixBase32 (0.00s)302 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)303 --- PASS: TestEncodeNixBase32/empty_input (0.00s)304--- PASS: TestGetStorePathHash (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)307 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)308 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)309=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum310=== CONT TestUploadMultipart_SupersededByPeer/missing311=== CONT TestPartSizeForNAR/small_stays_at_minimum312--- PASS: TestPartSizeForNAR (0.00s)313 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)314 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)315 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)316 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)317 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)318 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)319 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)320=== CONT TestSetClientTLSErrors/missing_cert_file321=== CONT TestFilterOversizedClosures/no_limit_keeps_everything322=== CONT TestSetClientTLSErrors/invalid_ca_file323=== CONT TestSetClientTLSErrors/missing_ca_file324=== CONT TestSetClientTLSErrors/missing_key_file325=== CONT TestFilterOversizedClosures/all_closures_skipped3262026/09/10 03:42:33 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=50327=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3282026/09/10 03:42:33 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=2000329--- PASS: TestFilterOversizedClosures (0.00s)330 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)331 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)332 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)333=== CONT TestSetClientTLS/rejects_connection_without_client_cert334=== CONT TestSetClientTLS/preserves_debug_logging_transport335--- PASS: TestSetClientTLSErrors (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)337 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)339 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)340--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)341 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)342 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)343=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA344--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)3452026/09/10 03:42:33 http: TLS handshake error from 127.0.0.1:63379: remote error: tls: bad certificate346--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)347--- PASS: TestSetClientTLS (0.00s)348 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)349 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)350 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)351--- PASS: TestDumpPathWriterError (0.03s)352--- PASS: TestDumpPathSingleFile (0.04s)353--- PASS: TestCaseHackSuffix (0.03s)354--- PASS: TestDumpPathMatchesNix (0.06s)355--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)356PASS357Running server tests...358The files belonging to this database system will be owned by user "_nixbld10".359This user must also own the server process.360361The database cluster will be initialized with locale "C".362The default database encoding has accordingly been set to "SQL_ASCII".363The default text search configuration will be set to "english".364365Data page checksums are enabled.366367creating directory /nix/var/nix/builds/nix-85886-2909774477/postgres2427832401/data ... ok368creating subdirectories ... ok369selecting dynamic shared memory implementation ... posix370selecting default "max_connections" ... 100371selecting default "shared_buffers" ... 128MB372selecting default time zone ... UTC373creating configuration files ... ok374running bootstrap script ... ok375performing post-bootstrap initialization ... ok376syncing data to disk ... ok377378initdb: warning: enabling "trust" authentication for local connections379initdb: 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.380381Success. You can now start the database server using:382383 pg_ctl -D /nix/var/nix/builds/nix-85886-2909774477/postgres2427832401/data -l logfile start3843852026-09-10 03:42:37.519 UTC [85984] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit3862026-09-10 03:42:37.519 UTC [85984] LOG: listening on Unix socket "/nix/var/nix/builds/nix-85886-2909774477/postgres2427832401/.s.PGSQL.5432"3872026-09-10 03:42:37.521 UTC [85991] LOG: database system was shut down at 2026-09-10 03:42:37 UTC3882026-09-10 03:42:37.522 UTC [85984] LOG: database system is ready to accept connections389/nix/var/nix/builds/nix-85886-2909774477/postgres2427832401:5432 - accepting connections390=== RUN TestService_AuthMiddleware391=== PAUSE TestService_AuthMiddleware392=== RUN TestService_AuthMiddleware_MTLSProxyHeader393=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader394=== RUN TestService_AuthMiddleware_MTLSBoundSubjects395=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects396=== RUN TestService_ReadAuthMiddleware397=== PAUSE TestService_ReadAuthMiddleware398=== RUN TestService_AuthMiddleware_OIDC399=== PAUSE TestService_AuthMiddleware_OIDC400=== RUN TestService_RequireScope_OIDC401=== PAUSE TestService_RequireScope_OIDC402=== RUN TestService_ReadScope_PublicByDefault403=== PAUSE TestService_ReadScope_PublicByDefault404=== RUN TestCacheConfigHandler405=== PAUSE TestCacheConfigHandler406=== RUN TestCacheStatsHandler407=== PAUSE TestCacheStatsHandler408=== RUN TestClientCADerivations409=== PAUSE TestClientCADerivations410=== RUN TestClientErrorHandling411=== PAUSE TestClientErrorHandling412=== RUN TestClientIntegration413=== PAUSE TestClientIntegration414=== RUN TestClientMultipleUploads415=== PAUSE TestClientMultipleUploads416=== RUN TestClientWithDependencies417=== PAUSE TestClientWithDependencies418=== RUN TestPinProtectsFromGC419=== PAUSE TestPinProtectsFromGC420=== RUN TestResolveDBConnectionString421=== PAUSE TestResolveDBConnectionString422=== RUN TestGCAdvisoryLockBlocksConcurrentRun4232026-09-10 03:42:39.818 UTC [86062] ERROR: relation "goose_db_version" does not exist at character 364242026-09-10 03:42:39.818 UTC [86062] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4252026/09/10 03:42:39 OK 20241026095416_initial_model.sql (3.85ms)4262026/09/10 03:42:39 OK 20251210153512_drop_unused_gin_index.sql (414µs)4272026/09/10 03:42:39 OK 20251218171726_add_pins.sql (824.13µs)4282026/09/10 03:42:39 OK 20260628120000_add_object_size_and_stats.sql (925.08µs)4292026/09/10 03:42:39 goose: successfully migrated database to version: 202606281200004302026/09/10 03:42:39 OK 1_commit_pending_closure.sql (985.33µs)4312026/09/10 03:42:39 OK 2_object_stats_trigger.sql (194µs)4322026/09/10 03:42:39 goose: up to current file version: 2433--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.37s)434=== RUN TestGCBugBareHashReferences435=== PAUSE TestGCBugBareHashReferences436=== RUN TestGCMetrics437=== PAUSE TestGCMetrics438=== RUN TestGCTaskStore_StartNew439=== PAUSE TestGCTaskStore_StartNew440=== RUN TestGCTaskStore_DeduplicateSameParams441=== PAUSE TestGCTaskStore_DeduplicateSameParams442=== RUN TestGCTaskStore_ConflictDifferentParams443=== PAUSE TestGCTaskStore_ConflictDifferentParams444=== RUN TestGCTaskStore_GetEmpty445=== PAUSE TestGCTaskStore_GetEmpty446=== RUN TestGCTaskStore_GetReturnsLatest447=== PAUSE TestGCTaskStore_GetReturnsLatest448=== RUN TestGCTaskStore_CompletedAllowsNewTask449=== PAUSE TestGCTaskStore_CompletedAllowsNewTask450=== RUN TestGCTaskStore_PhaseUpdates451=== PAUSE TestGCTaskStore_PhaseUpdates452=== RUN TestGCTaskStore_Fail453=== PAUSE TestGCTaskStore_Fail454=== RUN TestGracefulShutdownDrainsInflight455=== PAUSE TestGracefulShutdownDrainsInflight456=== RUN TestService_healthCheckHandler457=== PAUSE TestService_healthCheckHandler458=== RUN TestService_readinessHandler459=== PAUSE TestService_readinessHandler460=== RUN TestGenerateLandingPage461=== PAUSE TestGenerateLandingPage462=== RUN TestCacheConfigHandlerMaxNarSize463=== PAUSE TestCacheConfigHandlerMaxNarSize464=== RUN TestCreatePendingClosureRejectsOversizedNAR465=== PAUSE TestCreatePendingClosureRejectsOversizedNAR466=== RUN TestNARDeduplicationMetadataUploadBug467=== PAUSE TestNARDeduplicationMetadataUploadBug468=== RUN TestMetricsInventory469=== PAUSE TestMetricsInventory470=== RUN TestService_NativeMTLS471=== PAUSE TestService_NativeMTLS472=== RUN TestServerTLSConfig473=== PAUSE TestServerTLSConfig474=== RUN TestMultipartCleanup475=== PAUSE TestMultipartCleanup476=== RUN TestObjectStatsTrigger477=== PAUSE TestObjectStatsTrigger478=== RUN TestOrphanedObjectsGC479=== PAUSE TestOrphanedObjectsGC480=== RUN TestOrphanedObjectsGCStressTest481=== PAUSE TestOrphanedObjectsGCStressTest482=== RUN TestResurrectedObjectNotDeleted483=== PAUSE TestResurrectedObjectNotDeleted484=== RUN TestParseSingleRange485=== PAUSE TestParseSingleRange486=== RUN TestIsValidCachePath487=== PAUSE TestIsValidCachePath488=== RUN TestReadProxyNarinfo489=== PAUSE TestReadProxyNarinfo490=== RUN TestReadProxyNarinfoAlreadyDecompressed491=== PAUSE TestReadProxyNarinfoAlreadyDecompressed492=== RUN TestReadProxyNarStreaming493=== PAUSE TestReadProxyNarStreaming494=== RUN TestReadProxy404495=== PAUSE TestReadProxy404496=== RUN TestReadProxyInvalidPath497=== PAUSE TestReadProxyInvalidPath498=== RUN TestReadProxyHead499=== PAUSE TestReadProxyHead500=== RUN TestReadProxyConditionalGet501=== PAUSE TestReadProxyConditionalGet502=== RUN TestReadProxyRootRedirectsToIndexHTML503=== PAUSE TestReadProxyRootRedirectsToIndexHTML504=== RUN TestReadProxyDisabled505=== PAUSE TestReadProxyDisabled506=== RUN TestReadRedirectNar507=== PAUSE TestReadRedirectNar508=== RUN TestReadRedirectKeepsNarinfoProxied509=== PAUSE TestReadRedirectKeepsNarinfoProxied510=== RUN TestReadProxyRangeRequest511=== PAUSE TestReadProxyRangeRequest512=== RUN TestReadRedirectUsesPublicS3URL513=== PAUSE TestReadRedirectUsesPublicS3URL514=== RUN TestRedundantMultipartUpload515=== PAUSE TestRedundantMultipartUpload516=== RUN TestCompleteMultipartUpload_ErrorButObjectExists517=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists518=== RUN TestCompletedNarNotReofferedAcrossClosures519=== PAUSE TestCompletedNarNotReofferedAcrossClosures520=== RUN TestPresignedUploadRegisteredBeforeCommit521=== PAUSE TestPresignedUploadRegisteredBeforeCommit522=== RUN TestService_Rustfstest523=== PAUSE TestService_Rustfstest524=== RUN TestParseSize525=== PAUSE TestParseSize526=== RUN TestSkippedUploadsHandler527=== PAUSE TestSkippedUploadsHandler528=== RUN TestSystemdListenerNotActivated529--- PASS: TestSystemdListenerNotActivated (0.00s)530=== RUN TestWatchdogBeatsWhenHealthy531--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)532=== RUN TestWatchdogSkipsWhenUnhealthy5332026/09/10 03:42:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5342026/09/10 03:42:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5352026/09/10 03:42:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5362026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5372026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5382026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5392026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5402026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5412026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5422026/09/10 03:42:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"543--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)544=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle545=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle546=== RUN TestProxyWriteTimeout547=== PAUSE TestProxyWriteTimeout548=== RUN TestIsValidUploadKey549=== PAUSE TestIsValidUploadKey550=== RUN TestUploadHandlersRejectInvalidKeys551=== PAUSE TestUploadHandlersRejectInvalidKeys552=== RUN TestUploadHandlersRejectOversizedBody553=== PAUSE TestUploadHandlersRejectOversizedBody554=== RUN TestService_cleanupPendingClosuresHandler555=== PAUSE TestService_cleanupPendingClosuresHandler556=== RUN TestService_createPendingClosureHandler557=== PAUSE TestService_createPendingClosureHandler558=== RUN TestService_verifyS3Integrity559=== PAUSE TestService_verifyS3Integrity560=== RUN TestCompleteMultipartUnregistered561=== PAUSE TestCompleteMultipartUnregistered562=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT563=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT564=== CONT TestService_AuthMiddleware565=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT566=== CONT TestGCTaskStore_DeduplicateSameParams567--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)568=== CONT TestMultipartCleanup569=== CONT TestService_readinessHandler570=== CONT TestReadRedirectUsesPublicS3URL571=== CONT TestObjectStatsTrigger572=== CONT TestServerTLSConfig573=== RUN TestServerTLSConfig/no_client_CA574=== CONT TestService_NativeMTLS575=== CONT TestNARDeduplicationMetadataUploadBug576=== PAUSE TestServerTLSConfig/no_client_CA577=== CONT TestMetricsInventory578=== RUN TestServerTLSConfig/missing_CA_file579=== PAUSE TestServerTLSConfig/missing_CA_file580=== RUN TestServerTLSConfig/not_a_PEM_file581=== PAUSE TestServerTLSConfig/not_a_PEM_file582=== CONT TestProxyWriteTimeout583=== RUN TestProxyWriteTimeout/narinfo584=== PAUSE TestProxyWriteTimeout/narinfo585=== RUN TestProxyWriteTimeout/1_GiB_nar586=== PAUSE TestProxyWriteTimeout/1_GiB_nar587=== RUN TestProxyWriteTimeout/10_GiB_nar588=== PAUSE TestProxyWriteTimeout/10_GiB_nar589=== RUN TestProxyWriteTimeout/unknown_size590=== PAUSE TestProxyWriteTimeout/unknown_size591=== CONT TestCompleteMultipartUnregistered5922026-09-10 03:42:40.444 UTC [86084] ERROR: relation "goose_db_version" does not exist at character 365932026-09-10 03:42:40.444 UTC [86084] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5942026-09-10 03:42:40.448 UTC [86086] ERROR: relation "goose_db_version" does not exist at character 365952026-09-10 03:42:40.448 UTC [86086] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5962026-09-10 03:42:40.448 UTC [86085] ERROR: relation "goose_db_version" does not exist at character 365972026-09-10 03:42:40.448 UTC [86085] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5982026-09-10 03:42:40.449 UTC [86087] ERROR: relation "goose_db_version" does not exist at character 365992026-09-10 03:42:40.449 UTC [86087] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6002026-09-10 03:42:40.449 UTC [86088] ERROR: relation "goose_db_version" does not exist at character 366012026-09-10 03:42:40.449 UTC [86088] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6022026-09-10 03:42:40.451 UTC [86091] ERROR: relation "goose_db_version" does not exist at character 366032026-09-10 03:42:40.451 UTC [86091] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6042026-09-10 03:42:40.451 UTC [86090] ERROR: relation "goose_db_version" does not exist at character 366052026-09-10 03:42:40.451 UTC [86090] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6062026-09-10 03:42:40.451 UTC [86089] ERROR: relation "goose_db_version" does not exist at character 366072026-09-10 03:42:40.451 UTC [86089] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6082026-09-10 03:42:40.452 UTC [86093] ERROR: relation "goose_db_version" does not exist at character 366092026-09-10 03:42:40.452 UTC [86093] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6102026-09-10 03:42:40.452 UTC [86092] ERROR: relation "goose_db_version" does not exist at character 366112026-09-10 03:42:40.452 UTC [86092] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6122026/09/10 03:42:40 OK 20241026095416_initial_model.sql (6.6ms)6132026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)6142026/09/10 03:42:40 OK 20251218171726_add_pins.sql (1.68ms)6152026/09/10 03:42:40 OK 20241026095416_initial_model.sql (5.91ms)6162026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (1.75ms)6172026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006182026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)6192026/09/10 03:42:40 OK 20241026095416_initial_model.sql (7.08ms)6202026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (949.79µs)6212026/09/10 03:42:40 OK 1_commit_pending_closure.sql (1.69ms)6222026/09/10 03:42:40 OK 20241026095416_initial_model.sql (8.69ms)6232026/09/10 03:42:40 OK 2_object_stats_trigger.sql (454.96µs)6242026/09/10 03:42:40 goose: up to current file version: 26252026/09/10 03:42:40 OK 20251218171726_add_pins.sql (1.65ms)6262026/09/10 03:42:40 OK 20241026095416_initial_model.sql (9.05ms)6272026/09/10 03:42:40 OK 20241026095416_initial_model.sql (7.4ms)6282026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (605.5µs)6292026/09/10 03:42:40 OK 20251218171726_add_pins.sql (1.32ms)6302026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (849.13µs)6312026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (734.17µs)6322026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (1.61ms)6332026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006342026/09/10 03:42:40 OK 20241026095416_initial_model.sql (7.93ms)6352026/09/10 03:42:40 OK 20251218171726_add_pins.sql (1.85ms)6362026/09/10 03:42:40 OK 20241026095416_initial_model.sql (8.09ms)6372026/09/10 03:42:40 OK 20251218171726_add_pins.sql (1.52ms)6382026/09/10 03:42:40 OK 20251218171726_add_pins.sql (1.71ms)6392026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (1.83ms)6402026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006412026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (887.54µs)6422026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (464µs)6432026/09/10 03:42:40 OK 1_commit_pending_closure.sql (1.43ms)6442026/09/10 03:42:40 OK 2_object_stats_trigger.sql (205.38µs)6452026/09/10 03:42:40 goose: up to current file version: 26462026/09/10 03:42:40 OK 1_commit_pending_closure.sql (1.03ms)6472026/09/10 03:42:40 OK 2_object_stats_trigger.sql (216.17µs)6482026/09/10 03:42:40 goose: up to current file version: 26492026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (10.3ms)6502026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006512026/09/10 03:42:40 OK 20241026095416_initial_model.sql (19.01ms)6522026/09/10 03:42:40 OK 20241026095416_initial_model.sql (18.16ms)6532026/09/10 03:42:40 OK 20251218171726_add_pins.sql (9.95ms)6542026/09/10 03:42:40 OK 20251218171726_add_pins.sql (10.17ms)6552026/09/10 03:42:40 OK 1_commit_pending_closure.sql (873.08µs)6562026/09/10 03:42:40 OK 2_object_stats_trigger.sql (182.33µs)6572026/09/10 03:42:40 goose: up to current file version: 26582026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (36.39ms)6592026/09/10 03:42:40 OK 20251210153512_drop_unused_gin_index.sql (36.42ms)6602026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (46.74ms)6612026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006622026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (46.85ms)6632026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006642026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (41.56ms)6652026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006662026/09/10 03:42:40 OK 20251218171726_add_pins.sql (5.37ms)6672026/09/10 03:42:40 OK 1_commit_pending_closure.sql (5.32ms)6682026/09/10 03:42:40 OK 2_object_stats_trigger.sql (188.08µs)6692026/09/10 03:42:40 goose: up to current file version: 26702026/09/10 03:42:40 OK 1_commit_pending_closure.sql (5.84ms)6712026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (42.4ms)6722026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006732026/09/10 03:42:40 OK 2_object_stats_trigger.sql (291.75µs)6742026/09/10 03:42:40 goose: up to current file version: 26752026/09/10 03:42:40 OK 1_commit_pending_closure.sql (1.32ms)6762026/09/10 03:42:40 OK 2_object_stats_trigger.sql (190.75µs)6772026/09/10 03:42:40 goose: up to current file version: 26782026/09/10 03:42:40 OK 20251218171726_add_pins.sql (12.97ms)6792026/09/10 03:42:40 OK 1_commit_pending_closure.sql (7.21ms)6802026/09/10 03:42:40 OK 2_object_stats_trigger.sql (173µs)6812026/09/10 03:42:40 goose: up to current file version: 26822026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (8.48ms)6832026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006842026/09/10 03:42:40 OK 1_commit_pending_closure.sql (5.55ms)6852026/09/10 03:42:40 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)6862026/09/10 03:42:40 goose: successfully migrated database to version: 202606281200006872026/09/10 03:42:40 OK 2_object_stats_trigger.sql (229.54µs)6882026/09/10 03:42:40 goose: up to current file version: 26892026/09/10 03:42:40 OK 1_commit_pending_closure.sql (700µs)6902026/09/10 03:42:40 OK 2_object_stats_trigger.sql (195.71µs)6912026/09/10 03:42:40 goose: up to current file version: 26922026/09/10 03:42:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"6932026/09/10 03:42:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"694--- PASS: TestService_NativeMTLS (0.45s)695=== CONT TestService_verifyS3Integrity6962026/09/10 03:42:40 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"697--- PASS: TestService_AuthMiddleware (0.58s)698=== CONT TestService_createPendingClosureHandler6992026/09/10 03:42:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7002026/09/10 03:42:40 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst701--- PASS: TestCompleteMultipartUnregistered (0.72s)702=== CONT TestService_cleanupPendingClosuresHandler7032026/09/10 03:42:40 WARN readiness check failed error="closed pool"704--- PASS: TestService_readinessHandler (0.85s)705=== CONT TestUploadHandlersRejectOversizedBody706=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart707=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart708=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts709=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts710=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure711=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure712=== CONT TestUploadHandlersRejectInvalidKeys713=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info714=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info715=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal716=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal717=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key718=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key719=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key720=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key721=== CONT TestIsValidUploadKey722=== RUN TestIsValidUploadKey/narinfo723=== PAUSE TestIsValidUploadKey/narinfo724=== RUN TestIsValidUploadKey/nar_zst725=== PAUSE TestIsValidUploadKey/nar_zst726=== RUN TestIsValidUploadKey/nar_xz727=== PAUSE TestIsValidUploadKey/nar_xz728=== RUN TestIsValidUploadKey/nar_plain729=== PAUSE TestIsValidUploadKey/nar_plain730=== RUN TestIsValidUploadKey/listing731=== PAUSE TestIsValidUploadKey/listing732=== RUN TestIsValidUploadKey/build_log733=== PAUSE TestIsValidUploadKey/build_log734=== RUN TestIsValidUploadKey/build_log_home-manager_file735=== PAUSE TestIsValidUploadKey/build_log_home-manager_file736=== RUN TestIsValidUploadKey/build_log_plus_in_name737=== PAUSE TestIsValidUploadKey/build_log_plus_in_name738=== RUN TestIsValidUploadKey/build_log_question_mark739=== PAUSE TestIsValidUploadKey/build_log_question_mark740=== RUN TestIsValidUploadKey/build_log_equals741=== PAUSE TestIsValidUploadKey/build_log_equals742=== RUN TestIsValidUploadKey/realisation743=== PAUSE TestIsValidUploadKey/realisation744=== RUN TestIsValidUploadKey/realisation_plus_in_output745=== PAUSE TestIsValidUploadKey/realisation_plus_in_output746=== RUN TestIsValidUploadKey/nix-cache-info747=== PAUSE TestIsValidUploadKey/nix-cache-info748=== RUN TestIsValidUploadKey/index.html749=== PAUSE TestIsValidUploadKey/index.html750=== RUN TestIsValidUploadKey/narinfo_key,_nar_type751=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type752=== RUN TestIsValidUploadKey/nar_key,_narinfo_type753=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type754=== RUN TestIsValidUploadKey/listing_key,_narinfo_type755=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type756=== RUN TestIsValidUploadKey/traversal757=== PAUSE TestIsValidUploadKey/traversal758=== RUN TestIsValidUploadKey/traversal_nar759=== PAUSE TestIsValidUploadKey/traversal_nar760=== RUN TestIsValidUploadKey/absolute761=== PAUSE TestIsValidUploadKey/absolute762=== RUN TestIsValidUploadKey/empty_key763=== PAUSE TestIsValidUploadKey/empty_key764=== RUN TestIsValidUploadKey/unknown_type765=== PAUSE TestIsValidUploadKey/unknown_type766=== CONT TestReadProxy404767--- PASS: TestObjectStatsTrigger (1.03s)768=== CONT TestReadProxyRangeRequest7692026-09-10 03:42:41.154 UTC [86102] ERROR: relation "goose_db_version" does not exist at character 367702026-09-10 03:42:41.154 UTC [86102] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026-09-10 03:42:41.186 UTC [86105] ERROR: relation "goose_db_version" does not exist at character 367722026-09-10 03:42:41.186 UTC [86105] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026/09/10 03:42:41 OK 20241026095416_initial_model.sql (51.86ms)7742026/09/10 03:42:41 OK 20251210153512_drop_unused_gin_index.sql (8.25ms)7752026/09/10 03:42:41 OK 20251218171726_add_pins.sql (13.85ms)7762026/09/10 03:42:41 OK 20260628120000_add_object_size_and_stats.sql (14.26ms)7772026/09/10 03:42:41 goose: successfully migrated database to version: 202606281200007782026/09/10 03:42:41 OK 20241026095416_initial_model.sql (60.37ms)7792026/09/10 03:42:41 OK 1_commit_pending_closure.sql (8.35ms)7802026/09/10 03:42:41 OK 2_object_stats_trigger.sql (566.21µs)7812026/09/10 03:42:41 goose: up to current file version: 27822026/09/10 03:42:41 OK 20251210153512_drop_unused_gin_index.sql (8.24ms)7832026/09/10 03:42:41 INFO Received uploads request method=POST path=/api/pending_closures7842026-09-10 03:42:41.288 UTC [86106] ERROR: relation "goose_db_version" does not exist at character 367852026-09-10 03:42:41.288 UTC [86106] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/09/10 03:42:41 OK 20251218171726_add_pins.sql (10.76ms)7872026/09/10 03:42:41 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)7882026/09/10 03:42:41 goose: successfully migrated database to version: 202606281200007892026/09/10 03:42:41 OK 1_commit_pending_closure.sql (3.92ms)7902026/09/10 03:42:41 OK 2_object_stats_trigger.sql (563.29µs)7912026/09/10 03:42:41 goose: up to current file version: 27922026/09/10 03:42:41 OK 20241026095416_initial_model.sql (48.43ms)7932026/09/10 03:42:41 OK 20251210153512_drop_unused_gin_index.sql (10.9ms)7942026/09/10 03:42:41 OK 20251218171726_add_pins.sql (16.88ms)7952026/09/10 03:42:41 OK 20260628120000_add_object_size_and_stats.sql (12.07ms)7962026/09/10 03:42:41 goose: successfully migrated database to version: 202606281200007972026/09/10 03:42:41 OK 1_commit_pending_closure.sql (11.96ms)7982026/09/10 03:42:41 OK 2_object_stats_trigger.sql (1.1ms)7992026/09/10 03:42:41 goose: up to current file version: 28002026/09/10 03:42:41 INFO Received cleanup request method=DELETE path=/api/pending_closures8012026/09/10 03:42:41 INFO Aborted multipart uploads count=1802--- PASS: TestMultipartCleanup (1.33s)803=== CONT TestReadRedirectKeepsNarinfoProxied804--- PASS: TestReadRedirectUsesPublicS3URL (1.36s)805=== CONT TestReadRedirectNar8062026-09-10 03:42:41.496 UTC [86109] ERROR: relation "goose_db_version" does not exist at character 368072026-09-10 03:42:41.496 UTC [86109] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026/09/10 03:42:41 OK 20241026095416_initial_model.sql (80.03ms)8092026/09/10 03:42:41 INFO Received uploads request method=POST path=/api/pending_closures8102026/09/10 03:42:41 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)8112026/09/10 03:42:41 OK 20251218171726_add_pins.sql (4.23ms)8122026/09/10 03:42:41 OK 20260628120000_add_object_size_and_stats.sql (29.3ms)8132026/09/10 03:42:41 goose: successfully migrated database to version: 20260628120000814--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.52s)815=== CONT TestReadProxyDisabled8162026/09/10 03:42:41 OK 1_commit_pending_closure.sql (10.39ms)8172026/09/10 03:42:41 OK 2_object_stats_trigger.sql (1.58ms)8182026/09/10 03:42:41 goose: up to current file version: 28192026-09-10 03:42:41.687 UTC [86114] ERROR: relation "goose_db_version" does not exist at character 368202026-09-10 03:42:41.687 UTC [86114] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/09/10 03:42:41 OK 20241026095416_initial_model.sql (54.98ms)8222026/09/10 03:42:41 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)8232026/09/10 03:42:41 OK 20251218171726_add_pins.sql (10.72ms)8242026/09/10 03:42:41 OK 20260628120000_add_object_size_and_stats.sql (11.07ms)8252026/09/10 03:42:41 goose: successfully migrated database to version: 202606281200008262026/09/10 03:42:41 OK 1_commit_pending_closure.sql (1.42ms)8272026/09/10 03:42:41 OK 2_object_stats_trigger.sql (307.42µs)8282026/09/10 03:42:41 goose: up to current file version: 2829=== NAME TestNARDeduplicationMetadataUploadBug830 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-85886-2909774477/TestNARDeduplicationMetadataUploadBug2728037306/001/store/s1c6fd3rsa3xiwwigr6xm87sjp6q7sv6-file1.txt831--- PASS: TestMetricsInventory (1.78s)832=== CONT TestReadProxyRootRedirectsToIndexHTML8332026/09/10 03:42:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8342026/09/10 03:42:41 INFO Received uploads request method=POST path=/api/pending_closures8352026/09/10 03:42:41 INFO Received uploads request method=POST path=/api/pending_closures8362026/09/10 03:42:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8372026/09/10 03:42:42 INFO Uploading s1c6fd3rsa3xiwwigr6xm87sjp6q7sv6-file1.txt (160B)8382026/09/10 03:42:42 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8392026/09/10 03:42:42 WARN Failed to register uploaded object key=s1c6fd3rsa3xiwwigr6xm87sjp6q7sv6.ls error="server returned 404: 404 page not found\n"8402026/09/10 03:42:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8412026/09/10 03:42:42 INFO Signed narinfos id=1 count=18422026/09/10 03:42:42 INFO Uploading 1 narinfos8432026/09/10 03:42:42 WARN Failed to register uploaded object key=s1c6fd3rsa3xiwwigr6xm87sjp6q7sv6.narinfo error="server returned 404: 404 page not found\n"8442026/09/10 03:42:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8452026/09/10 03:42:42 INFO Completed upload id=18462026/09/10 03:42:42 INFO Upload complete. (131ms)847=== NAME TestNARDeduplicationMetadataUploadBug848 metadata_upload_test.go:54: Retrieved narinfo from S3:849 StorePath: /nix/var/nix/builds/nix-85886-2909774477/TestNARDeduplicationMetadataUploadBug2728037306/001/store/s1c6fd3rsa3xiwwigr6xm87sjp6q7sv6-file1.txt850 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst851 Compression: zstd852 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf853 NarSize: 160854 References: 855 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf856 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)857 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):858 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}859 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-85886-2909774477/TestNARDeduplicationMetadataUploadBug2728037306/001/store/j91mmm6gdb7iswn50gvx25whk2h1rg3n-file2.txt8602026/09/10 03:42:42 INFO Received uploads request method=POST path=/api/pending_closures8612026/09/10 03:42:42 INFO Received uploads request method=POST path=/api/pending_closures8622026/09/10 03:42:42 INFO Received uploads request method=POST path=/api/pending_closures8632026/09/10 03:42:42 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8642026-09-10 03:42:42.216 UTC [86132] ERROR: relation "goose_db_version" does not exist at character 368652026-09-10 03:42:42.216 UTC [86132] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8662026/09/10 03:42:42 INFO Received uploads request method=POST path=/api/pending_closures8672026/09/10 03:42:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8682026/09/10 03:42:42 WARN Failed to register uploaded object key=j91mmm6gdb7iswn50gvx25whk2h1rg3n.ls error="server returned 404: 404 page not found\n"8692026/09/10 03:42:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8702026/09/10 03:42:42 INFO Signed narinfos id=2 count=18712026/09/10 03:42:42 INFO Uploading 1 narinfos8722026/09/10 03:42:42 WARN Failed to register uploaded object key=j91mmm6gdb7iswn50gvx25whk2h1rg3n.narinfo error="server returned 404: 404 page not found\n"8732026/09/10 03:42:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8742026/09/10 03:42:42 INFO Completed upload id=28752026/09/10 03:42:42 INFO Upload complete. (131ms)876 metadata_upload_test.go:76: Retrieved narinfo from S3:877 StorePath: /nix/var/nix/builds/nix-85886-2909774477/TestNARDeduplicationMetadataUploadBug2728037306/001/store/j91mmm6gdb7iswn50gvx25whk2h1rg3n-file2.txt878 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst879 Compression: zstd880 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf881 NarSize: 160882 References: 883 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf884 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)885 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):886 {"version":1,"root":{"type":"regular","size":44}}8872026-09-10 03:42:42.293 UTC [86134] ERROR: relation "goose_db_version" does not exist at character 368882026-09-10 03:42:42.293 UTC [86134] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC889--- PASS: TestNARDeduplicationMetadataUploadBug (2.20s)890=== CONT TestReadProxyConditionalGet8912026/09/10 03:42:42 INFO Received cleanup request method=DELETE path=/api/pending_closures8922026/09/10 03:42:42 INFO Aborted multipart uploads count=08932026/09/10 03:42:42 INFO Received uploads request method=POST path=/api/pending_closures8942026/09/10 03:42:42 OK 20241026095416_initial_model.sql (196.1ms)8952026/09/10 03:42:42 OK 20241026095416_initial_model.sql (122.68ms)8962026/09/10 03:42:42 OK 20251210153512_drop_unused_gin_index.sql (14.89ms)8972026/09/10 03:42:42 OK 20251210153512_drop_unused_gin_index.sql (19.2ms)8982026/09/10 03:42:42 INFO Received cleanup request method=DELETE path=/api/pending_closures8992026/09/10 03:42:42 INFO Aborted multipart uploads count=19002026/09/10 03:42:42 OK 20251218171726_add_pins.sql (52.64ms)9012026/09/10 03:42:42 OK 20251218171726_add_pins.sql (46.65ms)9022026/09/10 03:42:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9032026-09-10 03:42:42.534 UTC [86106] ERROR: Closure does not exist: id=19042026-09-10 03:42:42.534 UTC [86106] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9052026-09-10 03:42:42.534 UTC [86106] STATEMENT: -- name: CommitPendingClosure :exec906 SELECT commit_pending_closure($1::bigint)907 908--- PASS: TestService_cleanupPendingClosuresHandler (1.69s)909=== CONT TestReadProxyHead9102026/09/10 03:42:42 OK 20260628120000_add_object_size_and_stats.sql (34.75ms)9112026/09/10 03:42:42 goose: successfully migrated database to version: 202606281200009122026/09/10 03:42:42 OK 20260628120000_add_object_size_and_stats.sql (39.03ms)9132026/09/10 03:42:42 goose: successfully migrated database to version: 202606281200009142026/09/10 03:42:42 OK 1_commit_pending_closure.sql (5.35ms)9152026/09/10 03:42:42 OK 2_object_stats_trigger.sql (479.5µs)9162026/09/10 03:42:42 goose: up to current file version: 29172026/09/10 03:42:42 OK 1_commit_pending_closure.sql (9.66ms)9182026/09/10 03:42:42 OK 2_object_stats_trigger.sql (617.79µs)9192026/09/10 03:42:42 goose: up to current file version: 29202026-09-10 03:42:42.588 UTC [86139] ERROR: relation "goose_db_version" does not exist at character 369212026-09-10 03:42:42.588 UTC [86139] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC922--- PASS: TestReadProxy404 (1.65s)923=== CONT TestReadProxyInvalidPath9242026/09/10 03:42:42 OK 20241026095416_initial_model.sql (158.22ms)9252026/09/10 03:42:42 OK 20251210153512_drop_unused_gin_index.sql (7.71ms)9262026/09/10 03:42:42 OK 20251218171726_add_pins.sql (17.38ms)9272026/09/10 03:42:42 OK 20260628120000_add_object_size_and_stats.sql (39.29ms)9282026/09/10 03:42:42 goose: successfully migrated database to version: 202606281200009292026/09/10 03:42:42 OK 1_commit_pending_closure.sql (7.38ms)9302026/09/10 03:42:42 OK 2_object_stats_trigger.sql (432.63µs)9312026/09/10 03:42:42 goose: up to current file version: 2932--- PASS: TestReadProxyRangeRequest (1.78s)933=== CONT TestCacheConfigHandlerMaxNarSize934--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)935=== CONT TestCreatePendingClosureRejectsOversizedNAR9362026/09/10 03:42:42 INFO Received uploads request method=POST path=/api/pending_closures937--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)938=== CONT TestService_Rustfstest9392026/09/10 03:42:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9402026-09-10 03:42:43.114 UTC [86144] ERROR: relation "goose_db_version" does not exist at character 369412026-09-10 03:42:43.114 UTC [86144] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC942--- PASS: TestReadRedirectKeepsNarinfoProxied (1.72s)943=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9442026/09/10 03:42:43 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjQxYTExMDUtZjAwOS00MWI5LWJhNTctZjEzYjM4NTlkMTgyLmRkYzE4NmVkLTJhYTMtNDRmZC1iN2FhLWQxM2VhODM1YzRkZXgxNzg5MDExNzYyMDAyMzA2MDAw parts=109452026/09/10 03:42:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9462026/09/10 03:42:43 INFO Completed upload id=19472026/09/10 03:42:43 INFO Received uploads request method=POST path=/api/pending_closures9482026/09/10 03:42:43 INFO Received uploads request method=POST path=/api/pending_closures9492026/09/10 03:42:43 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9502026/09/10 03:42:43 WARN Found objects in DB but missing from S3, will re-upload count=1951--- PASS: TestService_verifyS3Integrity (2.63s)952=== CONT TestSkippedUploadsHandler9532026/09/10 03:42:43 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000954--- PASS: TestSkippedUploadsHandler (0.00s)955=== CONT TestParseSize956--- PASS: TestParseSize (0.00s)957=== CONT TestGenerateLandingPage958--- PASS: TestGenerateLandingPage (0.00s)959=== CONT TestCompletedNarNotReofferedAcrossClosures9602026/09/10 03:42:43 OK 20241026095416_initial_model.sql (98.08ms)9612026/09/10 03:42:43 OK 20251210153512_drop_unused_gin_index.sql (12.66ms)9622026/09/10 03:42:43 OK 20251218171726_add_pins.sql (28.37ms)9632026/09/10 03:42:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9642026/09/10 03:42:43 OK 20260628120000_add_object_size_and_stats.sql (31.38ms)9652026/09/10 03:42:43 goose: successfully migrated database to version: 202606281200009662026/09/10 03:42:43 OK 1_commit_pending_closure.sql (11.83ms)9672026/09/10 03:42:43 OK 2_object_stats_trigger.sql (632.25µs)9682026/09/10 03:42:43 goose: up to current file version: 29692026/09/10 03:42:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjQxYTExMDUtZjAwOS00MWI5LWJhNTctZjEzYjM4NTlkMTgyLmExYzU2ZTljLTIwN2EtNDc2Zi1hODI2LTdiNGM4N2VlOTc1NXgxNzg5MDExNzYyMTkxNzI0MDAw parts=109702026/09/10 03:42:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete971--- PASS: TestReadRedirectNar (1.89s)972=== CONT TestPresignedUploadRegisteredBeforeCommit9732026/09/10 03:42:43 INFO Completed upload id=19742026/09/10 03:42:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009752026/09/10 03:42:43 INFO Received uploads request method=POST path=/api/pending_closures9762026/09/10 03:42:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures9772026/09/10 03:42:43 INFO Aborted multipart uploads count=09782026/09/10 03:42:43 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=09792026/09/10 03:42:43 INFO Vacuumed table table=pending_closures9802026/09/10 03:42:43 INFO Vacuumed table table=pending_objects9812026/09/10 03:42:43 INFO Vacuumed table table=multipart_uploads9822026/09/10 03:42:43 INFO Vacuumed table table=closures9832026/09/10 03:42:43 INFO Vacuumed table table=objects9842026/09/10 03:42:43 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000985--- PASS: TestService_createPendingClosureHandler (2.79s)986=== CONT TestCompleteMultipartUpload_ErrorButObjectExists987--- PASS: TestReadProxyDisabled (1.88s)988=== CONT TestGCTaskStore_PhaseUpdates989--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)990=== CONT TestService_healthCheckHandler9912026-09-10 03:42:43.680 UTC [86156] ERROR: relation "goose_db_version" does not exist at character 369922026-09-10 03:42:43.680 UTC [86156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC993--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.79s)994=== CONT TestGracefulShutdownDrainsInflight9952026/09/10 03:42:43 INFO Starting HTTP server address=127.0.0.1:634979962026/09/10 03:42:43 INFO Shutdown signal received, draining in-flight requests timeout=10s9972026-09-10 03:42:43.702 UTC [86157] ERROR: relation "goose_db_version" does not exist at character 369982026-09-10 03:42:43.702 UTC [86157] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9992026/09/10 03:42:43 OK 20241026095416_initial_model.sql (12.6ms)10002026/09/10 03:42:43 OK 20251210153512_drop_unused_gin_index.sql (730.04µs)10012026/09/10 03:42:43 OK 20251218171726_add_pins.sql (3.86ms)10022026/09/10 03:42:43 OK 20260628120000_add_object_size_and_stats.sql (5.21ms)10032026/09/10 03:42:43 goose: successfully migrated database to version: 2026062812000010042026/09/10 03:42:43 OK 1_commit_pending_closure.sql (1.3ms)10052026/09/10 03:42:43 OK 2_object_stats_trigger.sql (278.04µs)10062026/09/10 03:42:43 goose: up to current file version: 210072026/09/10 03:42:43 OK 20241026095416_initial_model.sql (14.65ms)10082026/09/10 03:42:43 OK 20251210153512_drop_unused_gin_index.sql (9.05ms)10092026/09/10 03:42:43 OK 20251218171726_add_pins.sql (10.97ms)1010--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1011=== CONT TestGCTaskStore_Fail1012--- PASS: TestGCTaskStore_Fail (0.00s)1013=== CONT TestIsValidCachePath1014=== RUN TestIsValidCachePath/narinfo1015=== PAUSE TestIsValidCachePath/narinfo1016=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1017=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1018=== RUN TestIsValidCachePath/nar_zst1019=== PAUSE TestIsValidCachePath/nar_zst1020=== RUN TestIsValidCachePath/nar_xz1021=== PAUSE TestIsValidCachePath/nar_xz1022=== RUN TestIsValidCachePath/nar_bz21023=== PAUSE TestIsValidCachePath/nar_bz21024=== RUN TestIsValidCachePath/nar_uncompressed1025=== PAUSE TestIsValidCachePath/nar_uncompressed1026=== RUN TestIsValidCachePath/ls1027=== PAUSE TestIsValidCachePath/ls1028=== RUN TestIsValidCachePath/log1029=== PAUSE TestIsValidCachePath/log1030=== RUN TestIsValidCachePath/realisation1031=== PAUSE TestIsValidCachePath/realisation1032=== RUN TestIsValidCachePath/nix-cache-info1033=== PAUSE TestIsValidCachePath/nix-cache-info1034=== RUN TestIsValidCachePath/index.html1035=== PAUSE TestIsValidCachePath/index.html1036=== RUN TestIsValidCachePath/traversal_parent1037=== PAUSE TestIsValidCachePath/traversal_parent1038=== RUN TestIsValidCachePath/traversal_in_middle1039=== PAUSE TestIsValidCachePath/traversal_in_middle1040=== RUN TestIsValidCachePath/invalid_char_e1041=== PAUSE TestIsValidCachePath/invalid_char_e1042=== RUN TestIsValidCachePath/invalid_char_u1043=== PAUSE TestIsValidCachePath/invalid_char_u1044=== RUN TestIsValidCachePath/random_path1045=== PAUSE TestIsValidCachePath/random_path1046=== RUN TestIsValidCachePath/empty1047=== PAUSE TestIsValidCachePath/empty1048=== RUN TestIsValidCachePath/leading_slash1049=== PAUSE TestIsValidCachePath/leading_slash1050=== RUN TestIsValidCachePath/wrong_extension1051=== PAUSE TestIsValidCachePath/wrong_extension1052=== RUN TestIsValidCachePath/short_hash1053=== PAUSE TestIsValidCachePath/short_hash1054=== CONT TestReadProxyNarStreaming10552026/09/10 03:42:43 OK 20260628120000_add_object_size_and_stats.sql (14.16ms)10562026/09/10 03:42:43 goose: successfully migrated database to version: 2026062812000010572026/09/10 03:42:43 OK 1_commit_pending_closure.sql (2.46ms)10582026/09/10 03:42:43 OK 2_object_stats_trigger.sql (262.88µs)10592026/09/10 03:42:43 goose: up to current file version: 210602026-09-10 03:42:43.852 UTC [86160] ERROR: relation "goose_db_version" does not exist at character 3610612026-09-10 03:42:43.852 UTC [86160] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1062--- PASS: TestReadProxyConditionalGet (1.57s)1063=== CONT TestReadProxyNarinfoAlreadyDecompressed10642026/09/10 03:42:43 OK 20241026095416_initial_model.sql (67.18ms)10652026/09/10 03:42:43 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)10662026-09-10 03:42:43.981 UTC [86163] ERROR: relation "goose_db_version" does not exist at character 3610672026-09-10 03:42:43.981 UTC [86163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10682026/09/10 03:42:43 OK 20251218171726_add_pins.sql (17.34ms)10692026/09/10 03:42:43 OK 20260628120000_add_object_size_and_stats.sql (17.24ms)10702026/09/10 03:42:43 goose: successfully migrated database to version: 2026062812000010712026/09/10 03:42:44 OK 1_commit_pending_closure.sql (7.34ms)10722026/09/10 03:42:44 OK 2_object_stats_trigger.sql (411.63µs)10732026/09/10 03:42:44 goose: up to current file version: 21074--- PASS: TestReadProxyHead (1.53s)1075=== CONT TestReadProxyNarinfo10762026/09/10 03:42:44 OK 20241026095416_initial_model.sql (80ms)10772026/09/10 03:42:44 OK 20251210153512_drop_unused_gin_index.sql (7.78ms)10782026/09/10 03:42:44 OK 20251218171726_add_pins.sql (16.65ms)10792026/09/10 03:42:44 OK 20260628120000_add_object_size_and_stats.sql (17.07ms)10802026/09/10 03:42:44 goose: successfully migrated database to version: 2026062812000010812026/09/10 03:42:44 OK 1_commit_pending_closure.sql (8.11ms)10822026/09/10 03:42:44 OK 2_object_stats_trigger.sql (544.04µs)10832026/09/10 03:42:44 goose: up to current file version: 210842026-09-10 03:42:44.208 UTC [86166] ERROR: relation "goose_db_version" does not exist at character 3610852026-09-10 03:42:44.208 UTC [86166] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1086--- PASS: TestReadProxyInvalidPath (1.58s)1087=== CONT TestGCTaskStore_GetReturnsLatest1088--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1089=== CONT TestGCTaskStore_CompletedAllowsNewTask1090--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1091=== CONT TestClientErrorHandling1092=== RUN TestClientErrorHandling/InvalidStorePath1093=== PAUSE TestClientErrorHandling/InvalidStorePath1094=== RUN TestClientErrorHandling/InvalidAuthToken1095=== PAUSE TestClientErrorHandling/InvalidAuthToken1096=== RUN TestClientErrorHandling/ServerNotAvailable1097=== PAUSE TestClientErrorHandling/ServerNotAvailable1098=== CONT TestGCTaskStore_StartNew1099--- PASS: TestGCTaskStore_StartNew (0.00s)1100=== CONT TestGCMetrics11012026-09-10 03:42:44.270 UTC [86167] ERROR: relation "goose_db_version" does not exist at character 3611022026-09-10 03:42:44.270 UTC [86167] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11032026/09/10 03:42:44 OK 20241026095416_initial_model.sql (71.65ms)11042026/09/10 03:42:44 OK 20251210153512_drop_unused_gin_index.sql (40.09ms)11052026/09/10 03:42:44 OK 20251218171726_add_pins.sql (17ms)11062026/09/10 03:42:44 OK 20260628120000_add_object_size_and_stats.sql (29.99ms)11072026/09/10 03:42:44 goose: successfully migrated database to version: 2026062812000011082026/09/10 03:42:44 OK 20241026095416_initial_model.sql (106.5ms)11092026/09/10 03:42:44 OK 1_commit_pending_closure.sql (4.22ms)11102026/09/10 03:42:44 OK 2_object_stats_trigger.sql (611.83µs)11112026/09/10 03:42:44 goose: up to current file version: 211122026/09/10 03:42:44 OK 20251210153512_drop_unused_gin_index.sql (8ms)11132026-09-10 03:42:44.420 UTC [86170] ERROR: relation "goose_db_version" does not exist at character 3611142026-09-10 03:42:44.420 UTC [86170] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11152026/09/10 03:42:44 OK 20251218171726_add_pins.sql (28.3ms)1116--- PASS: TestService_Rustfstest (1.53s)1117=== CONT TestGCBugBareHashReferences11182026/09/10 03:42:44 OK 20260628120000_add_object_size_and_stats.sql (27.6ms)11192026/09/10 03:42:44 goose: successfully migrated database to version: 2026062812000011202026/09/10 03:42:44 OK 1_commit_pending_closure.sql (9.08ms)11212026/09/10 03:42:44 OK 2_object_stats_trigger.sql (530.29µs)11222026/09/10 03:42:44 goose: up to current file version: 211232026-09-10 03:42:44.505 UTC [86173] ERROR: relation "goose_db_version" does not exist at character 3611242026-09-10 03:42:44.505 UTC [86173] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11252026/09/10 03:42:44 OK 20241026095416_initial_model.sql (66.91ms)11262026/09/10 03:42:44 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)11272026/09/10 03:42:44 OK 20251218171726_add_pins.sql (16.56ms)11282026-09-10 03:42:44.561 UTC [86174] ERROR: relation "goose_db_version" does not exist at character 3611292026-09-10 03:42:44.561 UTC [86174] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11302026/09/10 03:42:44 OK 20260628120000_add_object_size_and_stats.sql (15.56ms)11312026/09/10 03:42:44 goose: successfully migrated database to version: 2026062812000011322026/09/10 03:42:44 OK 1_commit_pending_closure.sql (10.79ms)11332026/09/10 03:42:44 OK 2_object_stats_trigger.sql (674.13µs)11342026/09/10 03:42:44 goose: up to current file version: 211352026/09/10 03:42:44 OK 20241026095416_initial_model.sql (84.05ms)11362026/09/10 03:42:44 OK 20251210153512_drop_unused_gin_index.sql (7.65ms)11372026/09/10 03:42:44 OK 20251218171726_add_pins.sql (19.89ms)11382026/09/10 03:42:44 INFO Received uploads request method=POST path=/api/pending_closures11392026/09/10 03:42:44 OK 20260628120000_add_object_size_and_stats.sql (17.79ms)11402026/09/10 03:42:44 goose: successfully migrated database to version: 2026062812000011412026/09/10 03:42:44 OK 20241026095416_initial_model.sql (69.08ms)11422026/09/10 03:42:44 OK 1_commit_pending_closure.sql (3.92ms)11432026/09/10 03:42:44 OK 2_object_stats_trigger.sql (713.67µs)11442026/09/10 03:42:44 goose: up to current file version: 211452026/09/10 03:42:44 OK 20251210153512_drop_unused_gin_index.sql (8.87ms)11462026/09/10 03:42:44 OK 20251218171726_add_pins.sql (33.1ms)11472026/09/10 03:42:44 OK 20260628120000_add_object_size_and_stats.sql (24.71ms)11482026/09/10 03:42:44 goose: successfully migrated database to version: 2026062812000011492026/09/10 03:42:44 OK 1_commit_pending_closure.sql (11.71ms)11502026/09/10 03:42:44 OK 2_object_stats_trigger.sql (722.79µs)11512026/09/10 03:42:44 goose: up to current file version: 211522026/09/10 03:42:44 INFO Received uploads request method=POST path=/api/pending_closures11532026-09-10 03:42:44.909 UTC [86175] ERROR: relation "goose_db_version" does not exist at character 3611542026-09-10 03:42:44.909 UTC [86175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026/09/10 03:42:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11562026/09/10 03:42:45 OK 20241026095416_initial_model.sql (85.41ms)11572026/09/10 03:42:45 OK 20251210153512_drop_unused_gin_index.sql (9.25ms)11582026/09/10 03:42:45 OK 20251218171726_add_pins.sql (29.1ms)11592026/09/10 03:42:45 OK 20260628120000_add_object_size_and_stats.sql (22.81ms)11602026/09/10 03:42:45 goose: successfully migrated database to version: 2026062812000011612026/09/10 03:42:45 OK 1_commit_pending_closure.sql (12.18ms)11622026/09/10 03:42:45 OK 2_object_stats_trigger.sql (826.17µs)11632026/09/10 03:42:45 goose: up to current file version: 211642026/09/10 03:42:45 INFO Received uploads request method=POST path=/api/pending_closures11652026/09/10 03:42:45 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11662026/09/10 03:42:45 INFO Received uploads request method=POST path=/api/pending_closures11672026-09-10 03:42:45.168 UTC [86176] ERROR: relation "goose_db_version" does not exist at character 3611682026-09-10 03:42:45.168 UTC [86176] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1169--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.79s)1170=== CONT TestResolveDBConnectionString1171=== RUN TestResolveDBConnectionString/flag_wins1172=== PAUSE TestResolveDBConnectionString/flag_wins1173=== RUN TestResolveDBConnectionString/file_when_flag_empty1174=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1175=== RUN TestResolveDBConnectionString/missing_file_is_an_error1176=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1177=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1178=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1179=== RUN TestResolveDBConnectionString/nothing_configured1180=== PAUSE TestResolveDBConnectionString/nothing_configured1181=== CONT TestPinProtectsFromGC11822026-09-10 03:42:45.249 UTC [86179] ERROR: relation "goose_db_version" does not exist at character 3611832026-09-10 03:42:45.249 UTC [86179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11842026/09/10 03:42:45 OK 20241026095416_initial_model.sql (94.37ms)11852026/09/10 03:42:45 OK 20251210153512_drop_unused_gin_index.sql (13.24ms)11862026/09/10 03:42:45 OK 20251218171726_add_pins.sql (32.91ms)11872026/09/10 03:42:45 INFO Received uploads request method=POST path=/api/pending_closures11882026/09/10 03:42:45 OK 20260628120000_add_object_size_and_stats.sql (33.43ms)11892026/09/10 03:42:45 goose: successfully migrated database to version: 2026062812000011902026/09/10 03:42:45 OK 1_commit_pending_closure.sql (17.06ms)11912026/09/10 03:42:45 OK 2_object_stats_trigger.sql (949.54µs)11922026/09/10 03:42:45 goose: up to current file version: 211932026/09/10 03:42:45 OK 20241026095416_initial_model.sql (147.55ms)11942026/09/10 03:42:45 OK 20251210153512_drop_unused_gin_index.sql (6.2ms)11952026/09/10 03:42:45 OK 20251218171726_add_pins.sql (41.62ms)11962026/09/10 03:42:45 OK 20260628120000_add_object_size_and_stats.sql (46.09ms)11972026/09/10 03:42:45 goose: successfully migrated database to version: 2026062812000011982026-09-10 03:42:45.549 UTC [86180] ERROR: relation "goose_db_version" does not exist at character 3611992026-09-10 03:42:45.549 UTC [86180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12002026/09/10 03:42:45 OK 1_commit_pending_closure.sql (6.74ms)12012026/09/10 03:42:45 OK 2_object_stats_trigger.sql (1.03ms)12022026/09/10 03:42:45 goose: up to current file version: 212032026/09/10 03:42:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12042026/09/10 03:42:45 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjQxYTExMDUtZjAwOS00MWI5LWJhNTctZjEzYjM4NTlkMTgyLjQ1MWFmNTdkLTRjMzAtNGIxMi1iMzQwLWY3YWMzYzE3MTJmNHgxNzg5MDExNzY1Mzc2OTgxMDAw12052026/09/10 03:42:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjQxYTExMDUtZjAwOS00MWI5LWJhNTctZjEzYjM4NTlkMTgyLjQ1MWFmNTdkLTRjMzAtNGIxMi1iMzQwLWY3YWMzYzE3MTJmNHgxNzg5MDExNzY1Mzc2OTgxMDAw parts=11206--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.10s)1207=== CONT TestClientWithDependencies1208--- PASS: TestService_healthCheckHandler (2.12s)1209=== CONT TestClientMultipleUploads12102026/09/10 03:42:45 OK 20241026095416_initial_model.sql (97.66ms)12112026/09/10 03:42:45 OK 20251210153512_drop_unused_gin_index.sql (10.96ms)12122026/09/10 03:42:45 OK 20251218171726_add_pins.sql (11.95ms)12132026/09/10 03:42:45 OK 20260628120000_add_object_size_and_stats.sql (25.29ms)12142026/09/10 03:42:45 goose: successfully migrated database to version: 2026062812000012152026-09-10 03:42:45.762 UTC [86185] ERROR: relation "goose_db_version" does not exist at character 3612162026-09-10 03:42:45.762 UTC [86185] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12172026/09/10 03:42:45 OK 1_commit_pending_closure.sql (8.18ms)12182026/09/10 03:42:45 OK 2_object_stats_trigger.sql (411µs)12192026/09/10 03:42:45 goose: up to current file version: 21220--- PASS: TestReadProxyNarStreaming (2.08s)1221=== CONT TestClientIntegration12222026/09/10 03:42:45 OK 20241026095416_initial_model.sql (141.36ms)12232026/09/10 03:42:45 OK 20251210153512_drop_unused_gin_index.sql (11.09ms)12242026/09/10 03:42:45 OK 20251218171726_add_pins.sql (21.56ms)12252026/09/10 03:42:46 OK 20260628120000_add_object_size_and_stats.sql (52.34ms)12262026/09/10 03:42:46 goose: successfully migrated database to version: 2026062812000012272026/09/10 03:42:46 OK 1_commit_pending_closure.sql (12.63ms)12282026/09/10 03:42:46 OK 2_object_stats_trigger.sql (678.25µs)12292026/09/10 03:42:46 goose: up to current file version: 21230--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.22s)1231=== CONT TestRedundantMultipartUpload12322026/09/10 03:42:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1233--- PASS: TestReadProxyNarinfo (2.35s)1234=== CONT TestGCTaskStore_GetEmpty1235--- PASS: TestGCTaskStore_GetEmpty (0.00s)1236=== CONT TestService_RequireScope_OIDC12372026/09/10 03:42:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63546/oidc12382026/09/10 03:42:46 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjQxYTExMDUtZjAwOS00MWI5LWJhNTctZjEzYjM4NTlkMTgyLjg4MDFkOTkzLTRjYjItNGRiYy04OTNkLTUwODBiNDZmZDhmM3gxNzg5MDExNzY0ODk4Mjg1MDAw parts=1212392026/09/10 03:42:46 INFO Received uploads request method=POST path=/api/pending_closures1240--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.26s)1241=== CONT TestClientCADerivations12422026-09-10 03:42:46.580 UTC [86194] ERROR: relation "goose_db_version" does not exist at character 3612432026-09-10 03:42:46.580 UTC [86194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026/09/10 03:42:46 INFO Aborted multipart uploads count=012452026/09/10 03:42:46 WARN Force mode enabled - objects will be deleted immediately without grace period12462026/09/10 03:42:46 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=012472026/09/10 03:42:46 INFO Vacuumed table table=pending_closures12482026/09/10 03:42:46 INFO Vacuumed table table=pending_objects12492026/09/10 03:42:46 INFO Vacuumed table table=multipart_uploads12502026/09/10 03:42:46 INFO Vacuumed table table=closures12512026/09/10 03:42:46 INFO Vacuumed table table=objects1252--- PASS: TestGCMetrics (2.39s)1253=== CONT TestCacheStatsHandler12542026/09/10 03:42:46 OK 20241026095416_initial_model.sql (132.71ms)12552026/09/10 03:42:46 OK 20251210153512_drop_unused_gin_index.sql (13.1ms)12562026/09/10 03:42:46 OK 20251218171726_add_pins.sql (24.53ms)12572026/09/10 03:42:46 OK 20260628120000_add_object_size_and_stats.sql (17.66ms)12582026/09/10 03:42:46 goose: successfully migrated database to version: 2026062812000012592026/09/10 03:42:46 OK 1_commit_pending_closure.sql (7.93ms)12602026/09/10 03:42:46 OK 2_object_stats_trigger.sql (1.51ms)12612026/09/10 03:42:46 goose: up to current file version: 212622026-09-10 03:42:47.046 UTC [86198] ERROR: relation "goose_db_version" does not exist at character 3612632026-09-10 03:42:47.046 UTC [86198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1264--- PASS: TestGCBugBareHashReferences (2.65s)1265=== CONT TestCacheConfigHandler1266=== RUN TestCacheConfigHandler/full_config,_no_issuer1267=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1268=== RUN TestCacheConfigHandler/no_cache_url_configured1269=== PAUSE TestCacheConfigHandler/no_cache_url_configured1270=== RUN TestCacheConfigHandler/no_signing_keys1271=== PAUSE TestCacheConfigHandler/no_signing_keys1272=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1273=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1274=== CONT TestService_ReadScope_PublicByDefault12752026-09-10 03:42:47.219 UTC [86202] ERROR: relation "goose_db_version" does not exist at character 3612762026-09-10 03:42:47.219 UTC [86202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/09/10 03:42:47 OK 20241026095416_initial_model.sql (99.27ms)12782026/09/10 03:42:47 OK 20251210153512_drop_unused_gin_index.sql (8.19ms)12792026/09/10 03:42:47 OK 20251218171726_add_pins.sql (22.37ms)12802026/09/10 03:42:47 OK 20260628120000_add_object_size_and_stats.sql (36.3ms)12812026/09/10 03:42:47 goose: successfully migrated database to version: 2026062812000012822026/09/10 03:42:47 OK 1_commit_pending_closure.sql (7.29ms)12832026/09/10 03:42:47 OK 2_object_stats_trigger.sql (303.96µs)12842026/09/10 03:42:47 goose: up to current file version: 21285=== NAME TestPinProtectsFromGC1286 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-85886-2909774477/TestPinProtectsFromGC2249289109/001/store/sfjsgbafgz2dha6swx1flbn6kcyjs83i-pinned-file.txt1287 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-85886-2909774477/TestPinProtectsFromGC2249289109/001/store/xj0k965bxgsgs8jh884was4cjwrh5la3-unpinned-file.txt12882026-09-10 03:42:47.418 UTC [86206] ERROR: relation "goose_db_version" does not exist at character 3612892026-09-10 03:42:47.418 UTC [86206] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026/09/10 03:42:47 OK 20241026095416_initial_model.sql (189.23ms)12912026/09/10 03:42:47 OK 20251210153512_drop_unused_gin_index.sql (8.02ms)12922026/09/10 03:42:47 OK 20251218171726_add_pins.sql (22.78ms)12932026/09/10 03:42:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12942026/09/10 03:42:47 OK 20260628120000_add_object_size_and_stats.sql (26.17ms)12952026/09/10 03:42:47 goose: successfully migrated database to version: 2026062812000012962026/09/10 03:42:47 OK 1_commit_pending_closure.sql (1.09ms)12972026/09/10 03:42:47 OK 2_object_stats_trigger.sql (227.92µs)12982026/09/10 03:42:47 goose: up to current file version: 212992026/09/10 03:42:47 INFO Received uploads request method=POST path=/api/pending_closures13002026/09/10 03:42:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13012026/09/10 03:42:47 INFO Uploading sfjsgbafgz2dha6swx1flbn6kcyjs83i-pinned-file.txt (128B)13022026/09/10 03:42:47 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13032026/09/10 03:42:47 OK 20241026095416_initial_model.sql (64.76ms)13042026/09/10 03:42:47 WARN Failed to register uploaded object key=sfjsgbafgz2dha6swx1flbn6kcyjs83i.ls error="server returned 404: 404 page not found\n"13052026/09/10 03:42:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13062026/09/10 03:42:47 INFO Signed narinfos id=1 count=113072026/09/10 03:42:47 INFO Uploading 1 narinfos13082026/09/10 03:42:47 OK 20251210153512_drop_unused_gin_index.sql (7.58ms)13092026/09/10 03:42:47 WARN Failed to register uploaded object key=sfjsgbafgz2dha6swx1flbn6kcyjs83i.narinfo error="server returned 404: 404 page not found\n"13102026/09/10 03:42:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13112026/09/10 03:42:47 OK 20251218171726_add_pins.sql (18.86ms)13122026/09/10 03:42:47 INFO Completed upload id=113132026/09/10 03:42:47 INFO Upload complete. (142ms)13142026/09/10 03:42:47 OK 20260628120000_add_object_size_and_stats.sql (27.77ms)13152026/09/10 03:42:47 goose: successfully migrated database to version: 2026062812000013162026/09/10 03:42:47 OK 1_commit_pending_closure.sql (5.7ms)13172026/09/10 03:42:47 OK 2_object_stats_trigger.sql (241.54µs)13182026/09/10 03:42:47 goose: up to current file version: 213192026-09-10 03:42:47.633 UTC [86218] ERROR: relation "goose_db_version" does not exist at character 3613202026-09-10 03:42:47.633 UTC [86218] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13212026/09/10 03:42:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13222026/09/10 03:42:47 INFO Received uploads request method=POST path=/api/pending_closures13232026/09/10 03:42:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13242026/09/10 03:42:47 INFO Uploading xj0k965bxgsgs8jh884was4cjwrh5la3-unpinned-file.txt (128B)13252026/09/10 03:42:47 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13262026/09/10 03:42:47 WARN Failed to register uploaded object key=xj0k965bxgsgs8jh884was4cjwrh5la3.ls error="server returned 404: 404 page not found\n"13272026/09/10 03:42:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13282026/09/10 03:42:47 INFO Signed narinfos id=2 count=113292026/09/10 03:42:47 INFO Uploading 1 narinfos13302026/09/10 03:42:47 WARN Failed to register uploaded object key=xj0k965bxgsgs8jh884was4cjwrh5la3.narinfo error="server returned 404: 404 page not found\n"13312026/09/10 03:42:47 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13322026/09/10 03:42:47 INFO Completed upload id=213332026/09/10 03:42:47 INFO Upload complete. (116ms)13342026/09/10 03:42:47 INFO Received create pin request method=POST path=/api/pins/myapp13352026/09/10 03:42:47 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-85886-2909774477/TestPinProtectsFromGC2249289109/001/store/sfjsgbafgz2dha6swx1flbn6kcyjs83i-pinned-file.txt narinfo_key=sfjsgbafgz2dha6swx1flbn6kcyjs83i.narinfo13362026/09/10 03:42:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures13372026/09/10 03:42:47 INFO Garbage collection started13382026/09/10 03:42:47 INFO Aborted multipart uploads count=013392026/09/10 03:42:47 WARN Force mode enabled - objects will be deleted immediately without grace period13402026/09/10 03:42:47 OK 20241026095416_initial_model.sql (113.49ms)13412026/09/10 03:42:47 OK 20251210153512_drop_unused_gin_index.sql (12.81ms)13422026/09/10 03:42:47 OK 20251218171726_add_pins.sql (25.54ms)1343=== NAME TestClientWithDependencies1344 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-85886-2909774477/TestClientWithDependencies2739842759/001/store/4zjb4jikn68i5kn0f84q3q9shvgqrqbl-test-script13452026/09/10 03:42:47 OK 20260628120000_add_object_size_and_stats.sql (24.89ms)13462026/09/10 03:42:47 goose: successfully migrated database to version: 2026062812000013472026/09/10 03:42:47 OK 1_commit_pending_closure.sql (8.34ms)13482026/09/10 03:42:47 OK 2_object_stats_trigger.sql (390.04µs)13492026/09/10 03:42:47 goose: up to current file version: 21350 client_integration_test.go:596: Found 1 dependencies (including self)13512026-09-10 03:42:47.921 UTC [86233] ERROR: relation "goose_db_version" does not exist at character 3613522026-09-10 03:42:47.921 UTC [86233] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1353=== NAME TestClientMultipleUploads1354 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-85886-2909774477/TestClientMultipleUploads1363694062/001/store/y67p5hs7v75zkf9qbfdm34y6jlsibaq4-test-file-0.txt13552026-09-10 03:42:47.948 UTC [86238] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-10 03:42:47.948 UTC [86238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13572026/09/10 03:42:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13582026/09/10 03:42:47 INFO Received uploads request method=POST path=/api/pending_closures1359 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-85886-2909774477/TestClientMultipleUploads1363694062/001/store/vix0nrzpcxpb34ic5kaf4kly0dirdfgb-test-file-1.txt13602026/09/10 03:42:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13612026/09/10 03:42:47 INFO Uploading 4zjb4jikn68i5kn0f84q3q9shvgqrqbl-test-script (136B)13622026/09/10 03:42:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13632026/09/10 03:42:47 WARN Failed to register uploaded object key=log/l28n2l92b6xrihs7n6bvnbfk01zzyavl-test-script.drv error="server returned 404: 404 page not found\n"13642026/09/10 03:42:48 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=013652026/09/10 03:42:48 INFO Vacuumed table table=pending_closures13662026/09/10 03:42:48 WARN Failed to register uploaded object key=4zjb4jikn68i5kn0f84q3q9shvgqrqbl.ls error="server returned 404: 404 page not found\n"13672026/09/10 03:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13682026/09/10 03:42:48 INFO Signed narinfos id=1 count=113692026/09/10 03:42:48 INFO Uploading 1 narinfos13702026-09-10 03:42:48.022 UTC [86242] ERROR: relation "goose_db_version" does not exist at character 3613712026-09-10 03:42:48.022 UTC [86242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13722026/09/10 03:42:48 INFO Vacuumed table table=pending_objects13732026/09/10 03:42:48 INFO Vacuumed table table=multipart_uploads13742026/09/10 03:42:48 WARN Failed to register uploaded object key=4zjb4jikn68i5kn0f84q3q9shvgqrqbl.narinfo error="server returned 404: 404 page not found\n"13752026/09/10 03:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13762026/09/10 03:42:48 OK 20241026095416_initial_model.sql (92.67ms)13772026/09/10 03:42:48 INFO Completed upload id=113782026/09/10 03:42:48 INFO Upload complete. (119ms)1379=== NAME TestClientWithDependencies1380 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-85886-2909774477/TestClientWithDependencies2739842759/001/store) requires matching store prefix13812026/09/10 03:42:48 OK 20251210153512_drop_unused_gin_index.sql (6.64ms)13822026/09/10 03:42:48 INFO Vacuumed table table=closures13832026/09/10 03:42:48 INFO Vacuumed table table=objects13842026/09/10 03:42:48 OK 20251218171726_add_pins.sql (14.16ms)1385=== NAME TestClientMultipleUploads1386 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-85886-2909774477/TestClientMultipleUploads1363694062/001/store/pvlhmbvnazhjpwbv4w2jpdkd8dgz88wv-test-file-2.txt13872026/09/10 03:42:48 OK 20260628120000_add_object_size_and_stats.sql (6.92ms)13882026/09/10 03:42:48 goose: successfully migrated database to version: 2026062812000013892026/09/10 03:42:48 OK 1_commit_pending_closure.sql (982.88µs)13902026/09/10 03:42:48 OK 2_object_stats_trigger.sql (215.08µs)13912026/09/10 03:42:48 goose: up to current file version: 21392--- PASS: TestClientWithDependencies (2.48s)1393=== CONT TestService_ReadAuthMiddleware13942026/09/10 03:42:48 OK 20241026095416_initial_model.sql (102.75ms)13952026/09/10 03:42:48 OK 20251210153512_drop_unused_gin_index.sql (3.46ms)13962026/09/10 03:42:48 OK 20251218171726_add_pins.sql (15.21ms)13972026/09/10 03:42:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13982026/09/10 03:42:48 OK 20260628120000_add_object_size_and_stats.sql (36.19ms)13992026/09/10 03:42:48 goose: successfully migrated database to version: 2026062812000014002026/09/10 03:42:48 OK 20241026095416_initial_model.sql (91.53ms)14012026/09/10 03:42:48 OK 1_commit_pending_closure.sql (6.94ms)14022026/09/10 03:42:48 OK 2_object_stats_trigger.sql (220.04µs)14032026/09/10 03:42:48 goose: up to current file version: 214042026/09/10 03:42:48 OK 20251210153512_drop_unused_gin_index.sql (6.05ms)1405=== NAME TestClientIntegration1406 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-85886-2909774477/TestClientIntegration4203027643/002/store/8cbi0vgrpj8zd5qwqg637783bmbmfa4i-test-file.txt14072026/09/10 03:42:48 OK 20251218171726_add_pins.sql (17.99ms)14082026/09/10 03:42:48 OK 20260628120000_add_object_size_and_stats.sql (21.22ms)14092026/09/10 03:42:48 goose: successfully migrated database to version: 2026062812000014102026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures14112026/09/10 03:42:48 OK 1_commit_pending_closure.sql (1.24ms)14122026/09/10 03:42:48 OK 2_object_stats_trigger.sql (223.96µs)14132026/09/10 03:42:48 goose: up to current file version: 214142026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures14152026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures14162026/09/10 03:42:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14172026/09/10 03:42:48 INFO Uploading pvlhmbvnazhjpwbv4w2jpdkd8dgz88wv-test-file-2.txt (160B)14182026/09/10 03:42:48 INFO Uploading y67p5hs7v75zkf9qbfdm34y6jlsibaq4-test-file-0.txt (160B)14192026/09/10 03:42:48 INFO Uploading vix0nrzpcxpb34ic5kaf4kly0dirdfgb-test-file-1.txt (160B)14202026/09/10 03:42:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14212026/09/10 03:42:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14222026/09/10 03:42:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14232026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures14242026/09/10 03:42:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14252026/09/10 03:42:48 WARN Failed to register uploaded object key=pvlhmbvnazhjpwbv4w2jpdkd8dgz88wv.ls error="server returned 404: 404 page not found\n"14262026/09/10 03:42:48 WARN Failed to register uploaded object key=y67p5hs7v75zkf9qbfdm34y6jlsibaq4.ls error="server returned 404: 404 page not found\n"14272026/09/10 03:42:48 WARN Failed to register uploaded object key=vix0nrzpcxpb34ic5kaf4kly0dirdfgb.ls error="server returned 404: 404 page not found\n"14282026/09/10 03:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14292026/09/10 03:42:48 INFO Signed narinfos id=1 count=114302026/09/10 03:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14312026/09/10 03:42:48 INFO Signed narinfos id=2 count=114322026/09/10 03:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14332026/09/10 03:42:48 INFO Signed narinfos id=3 count=114342026/09/10 03:42:48 INFO Uploading 3 narinfos14352026-09-10 03:42:48.233 UTC [86258] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-10 03:42:48.233 UTC [86258] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/09/10 03:42:48 WARN Failed to register uploaded object key=y67p5hs7v75zkf9qbfdm34y6jlsibaq4.narinfo error="server returned 404: 404 page not found\n"14382026/09/10 03:42:48 WARN Failed to register uploaded object key=vix0nrzpcxpb34ic5kaf4kly0dirdfgb.narinfo error="server returned 404: 404 page not found\n"14392026/09/10 03:42:48 WARN Failed to register uploaded object key=pvlhmbvnazhjpwbv4w2jpdkd8dgz88wv.narinfo error="server returned 404: 404 page not found\n"14402026/09/10 03:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14412026/09/10 03:42:48 INFO Completed upload id=114422026/09/10 03:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14432026/09/10 03:42:48 INFO Completed upload id=214442026/09/10 03:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14452026/09/10 03:42:48 INFO Completed upload id=314462026/09/10 03:42:48 INFO Upload complete. (159ms)1447=== NAME TestClientMultipleUploads1448 client_integration_test.go:350: Uploaded 3 paths in 189.777458ms14492026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures14502026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures1451--- PASS: TestClientMultipleUploads (2.66s)1452=== CONT TestService_AuthMiddleware_OIDC14532026/09/10 03:42:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14542026/09/10 03:42:48 INFO Uploading 8cbi0vgrpj8zd5qwqg637783bmbmfa4i-test-file.txt (152B)14552026/09/10 03:42:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63589/oidc14562026/09/10 03:42:48 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14572026/09/10 03:42:48 WARN Failed to register uploaded object key=8cbi0vgrpj8zd5qwqg637783bmbmfa4i.ls error="server returned 404: 404 page not found\n"14582026/09/10 03:42:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14592026/09/10 03:42:48 INFO Signed narinfos id=1 count=114602026/09/10 03:42:48 INFO Uploading 1 narinfos14612026/09/10 03:42:48 WARN Failed to register uploaded object key=8cbi0vgrpj8zd5qwqg637783bmbmfa4i.narinfo error="server returned 404: 404 page not found\n"14622026/09/10 03:42:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14632026/09/10 03:42:48 INFO Completed upload id=114642026/09/10 03:42:48 INFO Upload complete. (172ms)1465=== NAME TestClientIntegration1466 client_integration_test.go:293: Retrieved narinfo from S3:1467 StorePath: /nix/var/nix/builds/nix-85886-2909774477/TestClientIntegration4203027643/002/store/8cbi0vgrpj8zd5qwqg637783bmbmfa4i-test-file.txt1468 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1469 Compression: zstd1470 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11471 NarSize: 1521472 References: 1473 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11474 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1475 client_integration_test.go:294: Decompressed .ls content (64 bytes):1476 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1477 client_integration_test.go:297: Testing garbage collection...14782026/09/10 03:42:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures14792026/09/10 03:42:48 INFO Garbage collection started14802026/09/10 03:42:48 INFO Aborted multipart uploads count=014812026/09/10 03:42:48 WARN Force mode enabled - objects will be deleted immediately without grace period14822026/09/10 03:42:48 OK 20241026095416_initial_model.sql (124.09ms)14832026/09/10 03:42:48 OK 20251210153512_drop_unused_gin_index.sql (10.49ms)14842026/09/10 03:42:48 OK 20251218171726_add_pins.sql (16.4ms)14852026/09/10 03:42:48 OK 20260628120000_add_object_size_and_stats.sql (24.1ms)14862026/09/10 03:42:48 goose: successfully migrated database to version: 2026062812000014872026/09/10 03:42:48 OK 1_commit_pending_closure.sql (5.42ms)14882026/09/10 03:42:48 OK 2_object_stats_trigger.sql (238.54µs)14892026/09/10 03:42:48 goose: up to current file version: 214902026/09/10 03:42:48 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=014912026/09/10 03:42:48 INFO Vacuumed table table=pending_closures14922026/09/10 03:42:48 INFO Vacuumed table table=pending_objects14932026/09/10 03:42:48 INFO Vacuumed table table=multipart_uploads14942026/09/10 03:42:48 INFO Vacuumed table table=closures1495=== RUN TestService_RequireScope_OIDC/builder_may_write1496=== PAUSE TestService_RequireScope_OIDC/builder_may_write1497=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1498=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1499=== RUN TestService_RequireScope_OIDC/ops_may_admin1500=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1501=== RUN TestService_RequireScope_OIDC/ops_may_not_write1502=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1503=== RUN TestService_RequireScope_OIDC/reader_may_not_write1504=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1505=== RUN TestService_RequireScope_OIDC/static_token_may_admin1506=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1507=== RUN TestService_RequireScope_OIDC/static_token_may_write1508=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1509=== RUN TestService_RequireScope_OIDC/reader_may_read1510=== PAUSE TestService_RequireScope_OIDC/reader_may_read1511=== RUN TestService_RequireScope_OIDC/writer_implies_read1512=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1513=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1514=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1515=== CONT TestResurrectedObjectNotDeleted15162026/09/10 03:42:48 INFO Vacuumed table table=objects1517=== NAME TestClientCADerivations1518 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-85886-2909774477/TestClientCADerivations1929170441/001/store/lvdmb68rnygpa7xig1s4zipq2f6sndwg-ca-test1519 client_ca_test.go:139: Found 1 dependencies (including self)15202026/09/10 03:42:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1521--- PASS: TestCacheStatsHandler (2.35s)1522=== CONT TestParseSingleRange1523=== RUN TestParseSingleRange/none1524=== PAUSE TestParseSingleRange/none1525=== RUN TestParseSingleRange/unknown_unit1526=== PAUSE TestParseSingleRange/unknown_unit1527=== RUN TestParseSingleRange/multi-range_ignored1528=== PAUSE TestParseSingleRange/multi-range_ignored1529=== RUN TestParseSingleRange/malformed_no_dash1530=== PAUSE TestParseSingleRange/malformed_no_dash1531=== RUN TestParseSingleRange/malformed_both_empty1532=== PAUSE TestParseSingleRange/malformed_both_empty1533=== RUN TestParseSingleRange/malformed_end_before_start1534=== PAUSE TestParseSingleRange/malformed_end_before_start1535=== RUN TestParseSingleRange/closed1536=== PAUSE TestParseSingleRange/closed1537=== RUN TestParseSingleRange/open-ended1538=== PAUSE TestParseSingleRange/open-ended1539=== RUN TestParseSingleRange/end_clamped_to_size1540=== PAUSE TestParseSingleRange/end_clamped_to_size1541=== RUN TestParseSingleRange/suffix1542=== PAUSE TestParseSingleRange/suffix1543=== RUN TestParseSingleRange/suffix_exceeds_size1544=== PAUSE TestParseSingleRange/suffix_exceeds_size1545=== RUN TestParseSingleRange/single_byte1546=== PAUSE TestParseSingleRange/single_byte1547=== RUN TestParseSingleRange/start_past_EOF1548=== PAUSE TestParseSingleRange/start_past_EOF1549=== RUN TestParseSingleRange/start_far_past_EOF1550=== PAUSE TestParseSingleRange/start_far_past_EOF1551=== CONT TestGCTaskStore_ConflictDifferentParams1552--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1553=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15542026/09/10 03:42:48 INFO Received uploads request method=POST path=/api/pending_closures15552026/09/10 03:42:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15562026/09/10 03:42:49 INFO Uploading lvdmb68rnygpa7xig1s4zipq2f6sndwg-ca-test (144B)15572026/09/10 03:42:49 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15582026/09/10 03:42:49 WARN Failed to register uploaded object key=log/sd5ja69q4x8fs7zj48d1glgwi91p2ys0-ca-test.drv error="server returned 404: 404 page not found\n"15592026/09/10 03:42:49 WARN Failed to register uploaded object key=lvdmb68rnygpa7xig1s4zipq2f6sndwg.ls error="server returned 404: 404 page not found\n"15602026/09/10 03:42:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15612026/09/10 03:42:49 INFO Signed narinfos id=1 count=115622026/09/10 03:42:49 INFO Uploading 1 narinfos15632026/09/10 03:42:49 WARN Failed to register uploaded object key=lvdmb68rnygpa7xig1s4zipq2f6sndwg.narinfo error="server returned 404: 404 page not found\n"15642026/09/10 03:42:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15652026/09/10 03:42:49 INFO Completed upload id=115662026/09/10 03:42:49 INFO Upload complete. (173ms)1567=== NAME TestClientCADerivations1568 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-85886-2909774477/TestClientCADerivations1929170441/001/store/lvdmb68rnygpa7xig1s4zipq2f6sndwg-ca-test1569 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1570 Compression: zstd1571 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1572 NarSize: 1441573 References: 1574 Deriver: /nix/var/nix/builds/nix-85886-2909774477/TestClientCADerivations1929170441/001/store/sd5ja69q4x8fs7zj48d1glgwi91p2ys0-ca-test.drv1575 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1576 client_ca_test.go:185: Checking for realisation files in S3...1577 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1578 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1579--- PASS: TestService_ReadScope_PublicByDefault (2.01s)1580=== CONT TestOrphanedObjectsGCStressTest1581=== NAME TestClientCADerivations1582 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket40?endpoint=http://localhost:63382®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-85886-2909774477/TestClientCADerivations1929170441/001/store'1583 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11584--- PASS: TestClientCADerivations (2.66s)1585=== CONT TestService_AuthMiddleware_MTLSProxyHeader15862026-09-10 03:42:49.126 UTC [86288] ERROR: relation "goose_db_version" does not exist at character 3615872026-09-10 03:42:49.126 UTC [86288] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15882026/09/10 03:42:49 OK 20241026095416_initial_model.sql (27.2ms)15892026/09/10 03:42:49 OK 20251210153512_drop_unused_gin_index.sql (532.63µs)15902026/09/10 03:42:49 OK 20251218171726_add_pins.sql (1.12ms)15912026/09/10 03:42:49 OK 20260628120000_add_object_size_and_stats.sql (2.42ms)15922026/09/10 03:42:49 goose: successfully migrated database to version: 2026062812000015932026/09/10 03:42:49 OK 1_commit_pending_closure.sql (1.69ms)15942026/09/10 03:42:49 OK 2_object_stats_trigger.sql (238.71µs)15952026/09/10 03:42:49 goose: up to current file version: 215962026/09/10 03:42:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1597--- PASS: TestService_ReadAuthMiddleware (1.31s)1598=== CONT TestOrphanedObjectsGC15992026/09/10 03:42:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjQxYTExMDUtZjAwOS00MWI5LWJhNTctZjEzYjM4NTlkMTgyLjA4NmU5MjBlLWIwYWQtNDdlYS04NjQwLTJkNDEzNTg3YTcxNHgxNzg5MDExNzY4MjMzNjU4MDAw parts=121600--- PASS: TestRedundantMultipartUpload (3.26s)1601=== CONT TestServerTLSConfig/no_client_CA1602=== CONT TestServerTLSConfig/not_a_PEM_file1603=== CONT TestServerTLSConfig/missing_CA_file1604--- PASS: TestServerTLSConfig (0.00s)1605 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1606 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1607 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1608=== CONT TestProxyWriteTimeout/narinfo1609=== CONT TestProxyWriteTimeout/10_GiB_nar1610=== CONT TestProxyWriteTimeout/unknown_size1611=== CONT TestProxyWriteTimeout/1_GiB_nar1612--- PASS: TestProxyWriteTimeout (0.00s)1613 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1614 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1615 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1616 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1617=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16182026/09/10 03:42:49 INFO Received complete multipart upload request method=POST path=/16192026-09-10 03:42:49.392 UTC [86292] ERROR: relation "goose_db_version" does not exist at character 3616202026-09-10 03:42:49.392 UTC [86292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16212026/09/10 03:42:49 OK 20241026095416_initial_model.sql (8.6ms)16222026/09/10 03:42:49 OK 20251210153512_drop_unused_gin_index.sql (670.08µs)16232026/09/10 03:42:49 OK 20251218171726_add_pins.sql (1.29ms)16242026/09/10 03:42:49 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)16252026/09/10 03:42:49 goose: successfully migrated database to version: 2026062812000016262026/09/10 03:42:49 OK 1_commit_pending_closure.sql (1.12ms)16272026/09/10 03:42:49 OK 2_object_stats_trigger.sql (266.33µs)16282026/09/10 03:42:49 goose: up to current file version: 21629=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16302026/09/10 03:42:49 INFO Received uploads request method=POST path=/16312026/09/10 03:42:49 WARN Rate limiter enabled after throttle name=s3-test rate=516322026/09/10 03:42:49 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1633=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1634 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101635 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001636--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.25s)1637=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16382026/09/10 03:42:49 INFO Received request for more parts method=POST path=/1639=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16402026/09/10 03:42:49 INFO Received uploads request method=POST path=/1641=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16422026/09/10 03:42:49 INFO Received complete multipart upload request method=POST path=/1643=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16442026/09/10 03:42:49 INFO Received request for more parts method=POST path=/1645=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16462026/09/10 03:42:49 INFO Received uploads request method=POST path=/1647--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1648 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1649 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1650 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1651 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1652=== CONT TestIsValidUploadKey/narinfo1653=== CONT TestIsValidUploadKey/realisation_plus_in_output1654=== CONT TestIsValidUploadKey/unknown_type1655=== CONT TestIsValidUploadKey/empty_key1656=== CONT TestIsValidUploadKey/absolute1657=== CONT TestIsValidUploadKey/traversal_nar1658=== CONT TestIsValidUploadKey/traversal1659=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1660=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1661=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1662=== CONT TestIsValidUploadKey/index.html1663=== CONT TestIsValidUploadKey/nix-cache-info1664=== CONT TestIsValidUploadKey/build_log_home-manager_file1665=== CONT TestIsValidUploadKey/realisation1666=== CONT TestIsValidUploadKey/build_log_equals1667=== CONT TestIsValidUploadKey/build_log_question_mark1668=== CONT TestIsValidUploadKey/build_log_plus_in_name1669=== CONT TestIsValidUploadKey/nar_plain1670=== CONT TestIsValidUploadKey/build_log1671=== CONT TestIsValidUploadKey/listing1672=== CONT TestIsValidUploadKey/nar_xz1673=== CONT TestIsValidUploadKey/nar_zst1674--- PASS: TestIsValidUploadKey (0.00s)1675 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1676 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1677 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1678 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1679 --- PASS: TestIsValidUploadKey/absolute (0.00s)1680 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1681 --- PASS: TestIsValidUploadKey/traversal (0.00s)1682 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1683 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1684 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1685 --- PASS: TestIsValidUploadKey/index.html (0.00s)1686 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1687 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1688 --- PASS: TestIsValidUploadKey/realisation (0.00s)1689 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1690 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1691 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1692 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1693 --- PASS: TestIsValidUploadKey/build_log (0.00s)1694 --- PASS: TestIsValidUploadKey/listing (0.00s)1695 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1696 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1697=== CONT TestIsValidCachePath/narinfo1698=== CONT TestIsValidCachePath/index.html1699=== CONT TestIsValidCachePath/short_hash1700=== CONT TestIsValidCachePath/wrong_extension1701=== CONT TestIsValidCachePath/leading_slash1702=== CONT TestIsValidCachePath/empty1703=== CONT TestIsValidCachePath/random_path1704=== CONT TestIsValidCachePath/invalid_char_u1705=== CONT TestIsValidCachePath/invalid_char_e1706=== CONT TestIsValidCachePath/traversal_in_middle1707=== CONT TestIsValidCachePath/traversal_parent1708=== CONT TestIsValidCachePath/nar_uncompressed1709=== CONT TestIsValidCachePath/nix-cache-info1710=== CONT TestIsValidCachePath/realisation1711=== CONT TestIsValidCachePath/log1712=== CONT TestIsValidCachePath/ls1713=== CONT TestIsValidCachePath/nar_xz1714=== CONT TestIsValidCachePath/nar_bz21715=== CONT TestIsValidCachePath/nar_zst1716=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1717=== CONT TestClientErrorHandling/InvalidStorePath1718--- PASS: TestIsValidCachePath (0.00s)1719 --- PASS: TestIsValidCachePath/narinfo (0.00s)1720 --- PASS: TestIsValidCachePath/index.html (0.00s)1721 --- PASS: TestIsValidCachePath/short_hash (0.00s)1722 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1723 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1724 --- PASS: TestIsValidCachePath/empty (0.00s)1725 --- PASS: TestIsValidCachePath/random_path (0.00s)1726 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1727 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1728 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1729 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1730 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1731 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1732 --- PASS: TestIsValidCachePath/realisation (0.00s)1733 --- PASS: TestIsValidCachePath/log (0.00s)1734 --- PASS: TestIsValidCachePath/ls (0.00s)1735 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1736 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1737 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1738 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)17392026-09-10 03:42:49.436 UTC [86294] ERROR: relation "goose_db_version" does not exist at character 3617402026-09-10 03:42:49.436 UTC [86294] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17412026/09/10 03:42:49 OK 20241026095416_initial_model.sql (61.83ms)17422026/09/10 03:42:49 OK 20251210153512_drop_unused_gin_index.sql (6.99ms)17432026/09/10 03:42:49 OK 20251218171726_add_pins.sql (16.01ms)1744=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1745=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1746=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1747=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1748=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1749=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1750=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1751=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1752=== CONT TestClientErrorHandling/ServerNotAvailable17532026/09/10 03:42:49 OK 20260628120000_add_object_size_and_stats.sql (9.12ms)17542026/09/10 03:42:49 goose: successfully migrated database to version: 2026062812000017552026/09/10 03:42:49 OK 1_commit_pending_closure.sql (2.28ms)17562026/09/10 03:42:49 OK 2_object_stats_trigger.sql (501.29µs)17572026/09/10 03:42:49 goose: up to current file version: 217582026/09/10 03:42:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1759--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1760 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1761 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1762 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1763=== CONT TestClientErrorHandling/InvalidAuthToken17642026-09-10 03:42:49.714 UTC [86305] ERROR: relation "goose_db_version" does not exist at character 3617652026-09-10 03:42:49.714 UTC [86305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17662026-09-10 03:42:49.728 UTC [86306] ERROR: relation "goose_db_version" does not exist at character 3617672026-09-10 03:42:49.728 UTC [86306] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17682026/09/10 03:42:49 OK 20241026095416_initial_model.sql (13.76ms)17692026/09/10 03:42:49 OK 20251210153512_drop_unused_gin_index.sql (368.92µs)17702026/09/10 03:42:49 OK 20251218171726_add_pins.sql (795.25µs)17712026-09-10 03:42:49.743 UTC [86307] ERROR: relation "goose_db_version" does not exist at character 3617722026-09-10 03:42:49.743 UTC [86307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17732026/09/10 03:42:49 OK 20260628120000_add_object_size_and_stats.sql (11.1ms)17742026/09/10 03:42:49 goose: successfully migrated database to version: 202606281200001775--- PASS: TestResurrectedObjectNotDeleted (1.09s)1776=== CONT TestResolveDBConnectionString/flag_wins1777=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1778=== CONT TestResolveDBConnectionString/nothing_configured1779=== CONT TestResolveDBConnectionString/missing_file_is_an_error1780=== CONT TestResolveDBConnectionString/file_when_flag_empty1781=== CONT TestCacheConfigHandler/full_config,_no_issuer1782=== CONT TestCacheConfigHandler/no_signing_keys1783=== CONT TestCacheConfigHandler/no_cache_url_configured1784=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1785--- PASS: TestCacheConfigHandler (0.00s)1786 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1787 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1788 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1789 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1790=== CONT TestService_RequireScope_OIDC/builder_may_write17912026/09/10 03:42:49 OK 1_commit_pending_closure.sql (961.08µs)1792--- PASS: TestResolveDBConnectionString (0.00s)1793 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1794 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1795 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1796 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1797 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17982026/09/10 03:42:49 OK 2_object_stats_trigger.sql (502.63µs)17992026/09/10 03:42:49 goose: up to current file version: 218002026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[write]1801=== CONT TestService_RequireScope_OIDC/static_token_may_admin1802=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1803=== CONT TestService_RequireScope_OIDC/writer_implies_read18042026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[write]1805=== CONT TestService_RequireScope_OIDC/reader_may_read18062026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[read]1807=== CONT TestService_RequireScope_OIDC/static_token_may_write1808=== CONT TestService_RequireScope_OIDC/ops_may_not_write18092026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[admin]1810=== CONT TestService_RequireScope_OIDC/reader_may_not_write18112026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[read]1812=== CONT TestService_RequireScope_OIDC/ops_may_admin18132026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[admin]1814=== CONT TestService_RequireScope_OIDC/builder_may_not_admin18152026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[write]1816=== CONT TestParseSingleRange/none1817=== CONT TestParseSingleRange/open-ended1818=== CONT TestParseSingleRange/start_far_past_EOF1819=== CONT TestParseSingleRange/start_past_EOF1820=== CONT TestParseSingleRange/single_byte1821=== CONT TestParseSingleRange/suffix_exceeds_size1822=== CONT TestParseSingleRange/suffix1823=== CONT TestParseSingleRange/end_clamped_to_size1824=== CONT TestParseSingleRange/multi-range_ignored1825=== CONT TestParseSingleRange/malformed_no_dash1826=== CONT TestParseSingleRange/malformed_both_empty1827=== CONT TestParseSingleRange/unknown_unit1828=== CONT TestParseSingleRange/closed1829=== CONT TestParseSingleRange/malformed_end_before_start1830--- PASS: TestParseSingleRange (0.00s)1831 --- PASS: TestParseSingleRange/none (0.00s)1832 --- PASS: TestParseSingleRange/open-ended (0.00s)1833 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1834 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1835 --- PASS: TestParseSingleRange/single_byte (0.00s)1836 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1837 --- PASS: TestParseSingleRange/suffix (0.00s)1838 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1839 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1840 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1841 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1842 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1843 --- PASS: TestParseSingleRange/closed (0.00s)1844 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1845=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1846--- PASS: TestService_RequireScope_OIDC (2.24s)1847 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1848 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1849 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1850 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1851 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1852 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1853 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1854 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1855 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1856 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18572026/09/10 03:42:49 OK 20241026095416_initial_model.sql (5.21ms)18582026/09/10 03:42:49 INFO OIDC auth successful provider=test scopes=[write]1859=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18602026/09/10 03:42:49 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]1861=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1862=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18632026/09/10 03:42:49 WARN Authentication failed token_preview=eyJhbGciOi...nA60PQc-cQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]18642026/09/10 03:42:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01865=== NAME TestPinProtectsFromGC1866 client_integration_test.go:711: Pin successfully protected closure from garbage collection18672026/09/10 03:42:49 OK 20251210153512_drop_unused_gin_index.sql (22.07ms)1868--- PASS: TestService_AuthMiddleware_OIDC (1.27s)1869 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1870 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1871 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1872 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18732026/09/10 03:42:49 OK 20251218171726_add_pins.sql (7.93ms)18742026/09/10 03:42:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.916823ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18752026/09/10 03:42:49 OK 20260628120000_add_object_size_and_stats.sql (13.47ms)18762026/09/10 03:42:49 goose: successfully migrated database to version: 202606281200001877--- PASS: TestPinProtectsFromGC (4.63s)18782026/09/10 03:42:49 OK 1_commit_pending_closure.sql (6.6ms)18792026/09/10 03:42:49 OK 2_object_stats_trigger.sql (215.58µs)18802026/09/10 03:42:49 goose: up to current file version: 218812026/09/10 03:42:49 OK 20241026095416_initial_model.sql (58.82ms)18822026/09/10 03:42:49 OK 20251210153512_drop_unused_gin_index.sql (938.54µs)18832026/09/10 03:42:49 OK 20251218171726_add_pins.sql (12.15ms)18842026/09/10 03:42:49 OK 20260628120000_add_object_size_and_stats.sql (10.37ms)18852026/09/10 03:42:49 goose: successfully migrated database to version: 2026062812000018862026/09/10 03:42:49 OK 1_commit_pending_closure.sql (1.06ms)18872026/09/10 03:42:49 OK 2_object_stats_trigger.sql (200.83µs)18882026/09/10 03:42:49 goose: up to current file version: 218892026/09/10 03:42:49 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18902026/09/10 03:42:49 WARN mTLS auth: bound subjects configured but subject DN unavailable18912026/09/10 03:42:49 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1892--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.92s)18932026/09/10 03:42:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.675965ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18942026-09-10 03:42:50.121 UTC [86308] ERROR: relation "goose_db_version" does not exist at character 3618952026-09-10 03:42:50.121 UTC [86308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18962026-09-10 03:42:50.132 UTC [86309] ERROR: relation "goose_db_version" does not exist at character 3618972026-09-10 03:42:50.132 UTC [86309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1898--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.09s)18992026/09/10 03:42:50 OK 20241026095416_initial_model.sql (73.84ms)19002026/09/10 03:42:50 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)19012026/09/10 03:42:50 OK 20241026095416_initial_model.sql (62.84ms)19022026/09/10 03:42:50 OK 20251218171726_add_pins.sql (3.92ms)19032026/09/10 03:42:50 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)19042026/09/10 03:42:50 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)19052026/09/10 03:42:50 goose: successfully migrated database to version: 2026062812000019062026/09/10 03:42:50 OK 20251218171726_add_pins.sql (3.5ms)19072026/09/10 03:42:50 OK 1_commit_pending_closure.sql (3.12ms)19082026/09/10 03:42:50 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)19092026/09/10 03:42:50 goose: successfully migrated database to version: 2026062812000019102026/09/10 03:42:50 OK 2_object_stats_trigger.sql (701.88µs)19112026/09/10 03:42:50 goose: up to current file version: 219122026/09/10 03:42:50 OK 1_commit_pending_closure.sql (2.72ms)19132026/09/10 03:42:50 OK 2_object_stats_trigger.sql (745.04µs)19142026/09/10 03:42:50 goose: up to current file version: 219152026-09-10 03:42:50.287 UTC [86310] ERROR: relation "goose_db_version" does not exist at character 3619162026-09-10 03:42:50.287 UTC [86310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19172026/09/10 03:42:50 OK 20241026095416_initial_model.sql (58.12ms)19182026/09/10 03:42:50 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)19192026/09/10 03:42:50 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=019202026/09/10 03:42:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=752.464ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1921=== NAME TestClientIntegration1922 client_integration_test.go:304: Objects in database after GC:1923 client_integration_test.go:304: Successfully deleted all objects with GC --force19242026/09/10 03:42:50 OK 20251218171726_add_pins.sql (12.53ms)19252026/09/10 03:42:50 OK 20260628120000_add_object_size_and_stats.sql (6.96ms)19262026/09/10 03:42:50 goose: successfully migrated database to version: 202606281200001927--- PASS: TestClientIntegration (4.57s)19282026/09/10 03:42:50 OK 1_commit_pending_closure.sql (3.54ms)19292026/09/10 03:42:50 OK 2_object_stats_trigger.sql (658.83µs)19302026/09/10 03:42:50 goose: up to current file version: 21931=== NAME TestOrphanedObjectsGC1932 orphaned_objects_gc_test.go:290: GC Test Summary:1933 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1934 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1935 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1936 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1937 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1938--- PASS: TestOrphanedObjectsGC (1.27s)19392026/09/10 03:42:50 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19402026/09/10 03:42:50 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1941=== NAME TestOrphanedObjectsGCStressTest1942 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1943 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1944 orphaned_objects_gc_test.go:509: Stress test completed successfully:1945 orphaned_objects_gc_test.go:510: - Active objects preserved: 201946 orphaned_objects_gc_test.go:511: - Objects deleted: 2101947 orphaned_objects_gc_test.go:512: - Total GC'd: 2101948--- PASS: TestOrphanedObjectsGCStressTest (1.80s)19492026/09/10 03:42:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74075771s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19502026/09/10 03:42:52 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"19512026/09/10 03:42:52 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19522026/09/10 03:42:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.082082ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19532026/09/10 03:42:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.974843ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19542026/09/10 03:42:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.362402ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19552026/09/10 03:42:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.664765002s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1956--- PASS: TestClientErrorHandling (0.00s)1957 --- PASS: TestClientErrorHandling/InvalidStorePath (1.12s)1958 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.09s)1959 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.69s)1960PASS1961{"timestamp":"2026-09-10T03:42:56.241403Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63483","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}19622026-09-10 03:42:56.329 UTC [85984] LOG: received smart shutdown request19632026-09-10 03:42:56.330 UTC [85984] LOG: background worker "logical replication launcher" (PID 85994) exited with exit code 119642026-09-10 03:42:56.339 UTC [85989] LOG: shutting down19652026-09-10 03:42:56.339 UTC [85989] LOG: checkpoint starting: shutdown immediate19662026-09-10 03:42:57.422 UTC [85989] LOG: checkpoint complete: wrote 13192 buffers (80.5%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.786 s, sync=0.294 s, total=1.083 s; sync files=17141, longest=0.001 s, average=0.001 s; distance=240171 kB, estimate=240171 kB; lsn=0/10217C50, redo lsn=0/10217C5019672026-09-10 03:42:57.426 UTC [85984] LOG: database system is shut down1968Running OIDC tests...1969=== RUN TestGlobMatch1970=== PAUSE TestGlobMatch1971=== RUN TestAudienceForIssuer1972=== PAUSE TestAudienceForIssuer1973=== RUN TestValidateToken_ValidToken1974=== PAUSE TestValidateToken_ValidToken1975=== RUN TestValidateToken_WrongAudience1976=== PAUSE TestValidateToken_WrongAudience1977=== RUN TestValidateToken_Expired1978=== PAUSE TestValidateToken_Expired1979=== RUN TestValidateToken_BoundClaimsMismatch1980=== PAUSE TestValidateToken_BoundClaimsMismatch1981=== RUN TestValidateToken_BoundSubjectMismatch1982=== PAUSE TestValidateToken_BoundSubjectMismatch1983=== RUN TestValidateToken_MultipleProviders1984=== PAUSE TestValidateToken_MultipleProviders1985=== RUN TestValidateToken_NoMatchingProvider1986=== PAUSE TestValidateToken_NoMatchingProvider1987=== RUN TestValidateToken_KubernetesServiceAccount1988=== PAUSE TestValidateToken_KubernetesServiceAccount1989=== RUN TestNewValidator_KubernetesRequiresCA1990=== PAUSE TestNewValidator_KubernetesRequiresCA1991=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1992=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1993=== RUN TestScopes_LegacyProviderDefaultsToWrite1994=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1995=== RUN TestScopes_Rules1996=== PAUSE TestScopes_Rules1997=== RUN TestScopes_ConfigValidation1998=== PAUSE TestScopes_ConfigValidation1999=== CONT TestGlobMatch2000=== RUN TestGlobMatch/foo_foo2001=== CONT TestValidateToken_MultipleProviders2002=== CONT TestScopes_ConfigValidation2003=== PAUSE TestGlobMatch/foo_foo2004=== RUN TestGlobMatch/foo_bar2005=== PAUSE TestGlobMatch/foo_bar2006=== RUN TestGlobMatch/*_2007=== PAUSE TestGlobMatch/*_2008=== RUN TestGlobMatch/*_anything2009=== PAUSE TestGlobMatch/*_anything2010=== RUN TestGlobMatch/foo*_foo2011=== PAUSE TestGlobMatch/foo*_foo2012=== RUN TestGlobMatch/foo*_foobar2013=== PAUSE TestGlobMatch/foo*_foobar2014=== RUN TestGlobMatch/foo*_bar2015=== PAUSE TestGlobMatch/foo*_bar2016=== RUN TestGlobMatch/*bar_bar2017=== PAUSE TestGlobMatch/*bar_bar2018=== RUN TestGlobMatch/*bar_foobar2019=== PAUSE TestGlobMatch/*bar_foobar2020=== RUN TestGlobMatch/*bar_foo2021=== PAUSE TestGlobMatch/*bar_foo2022=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2023=== CONT TestScopes_Rules2024=== CONT TestScopes_LegacyProviderDefaultsToWrite2025=== CONT TestValidateToken_KubernetesServiceAccount2026=== CONT TestNewValidator_KubernetesRequiresCA2027=== CONT TestValidateToken_Expired2028=== CONT TestValidateToken_BoundSubjectMismatch2029=== RUN TestGlobMatch/foo*bar_foobar2030=== PAUSE TestGlobMatch/foo*bar_foobar2031=== RUN TestGlobMatch/foo*bar_foo123bar2032=== PAUSE TestGlobMatch/foo*bar_foo123bar2033=== RUN TestGlobMatch/foo*bar_foobarbaz2034=== PAUSE TestGlobMatch/foo*bar_foobarbaz2035=== RUN TestGlobMatch/*/*_foo/bar2036=== PAUSE TestGlobMatch/*/*_foo/bar2037=== RUN TestGlobMatch/*/*_foo2038=== PAUSE TestGlobMatch/*/*_foo2039=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2040=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2041=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02042=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02043=== RUN TestGlobMatch/refs/*/main_refs/heads/main2044=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2045=== RUN TestGlobMatch/fo?_foo2046=== PAUSE TestGlobMatch/fo?_foo2047=== RUN TestGlobMatch/fo?_fo20482026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63656/oidc2049=== PAUSE TestGlobMatch/fo?_fo2050--- PASS: TestScopes_ConfigValidation (0.00s)2051=== RUN TestGlobMatch/fo?_fooo2052=== CONT TestValidateToken_BoundClaimsMismatch2053=== PAUSE TestGlobMatch/fo?_fooo2054=== RUN TestGlobMatch/?oo_foo2055=== PAUSE TestGlobMatch/?oo_foo2056=== RUN TestGlobMatch/?oo_boo2057=== PAUSE TestGlobMatch/?oo_boo2058=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2059=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2060=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2061=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2062=== CONT TestValidateToken_ValidToken20632026/09/10 03:42:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63657/oidc20642026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63661/oidc20652026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63662/oidc20662026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63660/oidc20672026/09/10 03:42:58 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:63663/oidc20682026/09/10 03:42:58 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12320692026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63673/oidc20702026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63674/oidc2071--- PASS: TestValidateToken_Expired (0.01s)2072=== CONT TestValidateToken_WrongAudience2073--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2074=== CONT TestValidateToken_NoMatchingProvider2075--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2076=== CONT TestAudienceForIssuer2077--- PASS: TestAudienceForIssuer (0.00s)2078=== CONT TestGlobMatch/foo_foo2079=== CONT TestGlobMatch/*/*_foo/bar2080=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2081=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2082=== CONT TestGlobMatch/?oo_boo2083=== CONT TestGlobMatch/?oo_foo2084=== CONT TestGlobMatch/fo?_fooo2085=== CONT TestGlobMatch/fo?_fo2086=== CONT TestGlobMatch/fo?_foo2087=== CONT TestGlobMatch/refs/*/main_refs/heads/main2088=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02089=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2090=== CONT TestGlobMatch/*/*_foo2091=== CONT TestGlobMatch/*bar_bar2092=== CONT TestGlobMatch/foo*bar_foobarbaz2093=== CONT TestGlobMatch/foo*bar_foo123bar2094=== CONT TestGlobMatch/foo*bar_foobar2095=== CONT TestGlobMatch/*bar_foo2096=== CONT TestGlobMatch/*bar_foobar2097=== CONT TestGlobMatch/foo*_foo2098=== CONT TestGlobMatch/foo*_bar2099=== CONT TestGlobMatch/foo*_foobar2100=== CONT TestGlobMatch/*_2101=== CONT TestGlobMatch/*_anything2102=== CONT TestGlobMatch/foo_bar2103--- PASS: TestGlobMatch (0.00s)2104 --- PASS: TestGlobMatch/foo_foo (0.00s)2105 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2106 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2107 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2108 --- PASS: TestGlobMatch/?oo_boo (0.00s)2109 --- PASS: TestGlobMatch/?oo_foo (0.00s)2110 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2111 --- PASS: TestGlobMatch/fo?_fo (0.00s)2112 --- PASS: TestGlobMatch/fo?_foo (0.00s)2113 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2114 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2115 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2116 --- PASS: TestGlobMatch/*/*_foo (0.00s)2117 --- PASS: TestGlobMatch/*bar_bar (0.00s)2118 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2119 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2120 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2121 --- PASS: TestGlobMatc2026/09/10 03:42:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63678/oidc2122h/*bar_foo (0.00s)2123 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2124 --- PASS: TestGlobMatch/foo*_foo (0.00s)2125 --- PASS: TestGlobMatch/foo*_bar (0.00s)2126 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2127 --- PASS: TestGlobMatch/*_ (0.00s)2128 --- PASS: TestGlobMatch/*_anything (0.00s)2129 --- PASS: TestGlobMatch/foo_bar (0.00s)21302026/09/10 03:42:58 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:636592131--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2132--- PASS: TestValidateToken_MultipleProviders (0.01s)21332026/09/10 03:42:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63679/oidc2134--- PASS: TestValidateToken_ValidToken (0.01s)2135--- PASS: TestValidateToken_WrongAudience (0.00s)2136--- PASS: TestValidateToken_NoMatchingProvider (0.01s)21372026/09/10 03:42:58 http: TLS handshake error from 127.0.0.1:63669: remote error: tls: bad certificate2138--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2139--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2140--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2141--- PASS: TestScopes_Rules (0.02s)2142PASS2143Running hook tests...2144=== RUN TestSendPathsEmpty2145=== PAUSE TestSendPathsEmpty2146=== RUN TestQueueEnqueueAndFetch2147=== PAUSE TestQueueEnqueueAndFetch2148=== RUN TestQueueDeduplication2149=== PAUSE TestQueueDeduplication2150=== RUN TestQueueRemove2151=== PAUSE TestQueueRemove2152=== RUN TestQueueFetchBatchLimit2153=== PAUSE TestQueueFetchBatchLimit2154=== RUN TestQueueRetryMovesToBack2155=== PAUSE TestQueueRetryMovesToBack2156=== RUN TestQueueFetchRemoveLifecycle2157=== PAUSE TestQueueFetchRemoveLifecycle2158=== RUN TestQueueConcurrentWriters2159=== PAUSE TestQueueConcurrentWriters2160=== RUN TestQueueRemoveLargeClosure2161=== PAUSE TestQueueRemoveLargeClosure2162=== RUN TestServerClientIntegration2163=== PAUSE TestServerClientIntegration2164=== RUN TestServerQueueError2165=== PAUSE TestServerQueueError2166=== RUN TestGetListenerSocketActivation2167 server_test.go:210: === RUN TestGetListenerSocketActivation2168 --- PASS: TestGetListenerSocketActivation (0.00s)2169 PASS2170 2171--- PASS: TestGetListenerSocketActivation (0.01s)2172=== RUN TestDrainIsolatesPoisonPath2173=== PAUSE TestDrainIsolatesPoisonPath2174=== RUN TestRunNotBlockedByPoisonHead2175=== PAUSE TestRunNotBlockedByPoisonHead2176=== RUN TestDrainGivesUpWhenServerDown2177=== PAUSE TestDrainGivesUpWhenServerDown2178=== RUN TestFailedPathPrunedByLaterClosure2179=== PAUSE TestFailedPathPrunedByLaterClosure2180=== RUN TestWorkerUploadsAndRemoves2181=== PAUSE TestWorkerUploadsAndRemoves2182=== RUN TestWorkerSkipsGCdPaths2183=== PAUSE TestWorkerSkipsGCdPaths2184=== RUN TestWorkerPrunesClosureDeps2185=== PAUSE TestWorkerPrunesClosureDeps2186=== RUN TestDrainTimeout2187=== PAUSE TestDrainTimeout2188=== CONT TestSendPathsEmpty2189=== CONT TestServerQueueError2190--- PASS: TestSendPathsEmpty (0.00s)2191=== CONT TestQueueRetryMovesToBack2192=== CONT TestQueueFetchBatchLimit2193=== CONT TestQueueRemove2194=== CONT TestQueueDeduplication2195=== CONT TestQueueEnqueueAndFetch2196=== CONT TestWorkerUploadsAndRemoves2197=== CONT TestDrainTimeout2198=== CONT TestWorkerPrunesClosureDeps2199=== CONT TestWorkerSkipsGCdPaths22002026/09/10 03:42:58 ERROR Failed to queue paths error="permission denied" count=12201--- PASS: TestServerQueueError (0.00s)2202=== CONT TestDrainGivesUpWhenServerDown22032026/09/10 03:42:58 INFO Upload queue status pending=222042026/09/10 03:42:58 INFO Uploading batch count=22205--- PASS: TestQueueRemove (0.01s)2206=== CONT TestFailedPathPrunedByLaterClosure2207--- PASS: TestQueueEnqueueAndFetch (0.01s)2208=== CONT TestRunNotBlockedByPoisonHead22092026/09/10 03:42:58 INFO Uploading batch count=22210--- PASS: TestQueueFetchBatchLimit (0.01s)2211=== CONT TestDrainIsolatesPoisonPath2212--- PASS: TestQueueRetryMovesToBack (0.01s)2213=== CONT TestQueueRemoveLargeClosure22142026/09/10 03:42:58 INFO Upload queue status pending=222152026/09/10 03:42:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-85886-2909774477/TestWorkerSkipsGCdPaths550456842/002/nonexistent22162026/09/10 03:42:58 INFO Uploading batch count=222172026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=222182026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainGivesUpWhenServerDown2314607143/002/a22192026/09/10 03:42:58 INFO Upload queue status pending=222202026/09/10 03:42:58 INFO Uploading batch count=122212026/09/10 03:42:58 INFO Uploading batch count=122222026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainGivesUpWhenServerDown2314607143/002/b2223--- PASS: TestQueueDeduplication (0.01s)2224=== CONT TestServerClientIntegration22252026/09/10 03:42:58 INFO Uploading batch count=222262026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=222272026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainGivesUpWhenServerDown2314607143/002/c22282026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainGivesUpWhenServerDown2314607143/002/d2229--- PASS: TestServerClientIntegration (0.00s)2230=== CONT TestQueueConcurrentWriters22312026/09/10 03:42:58 INFO Uploading batch count=222322026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=222332026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainGivesUpWhenServerDown2314607143/002/e22342026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainGivesUpWhenServerDown2314607143/002/f22352026/09/10 03:42:58 INFO Uploading batch count=122362026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=122372026/09/10 03:42:58 ERROR Drain finished with paths left in queue remaining=1022382026/09/10 03:42:58 INFO Uploading batch count=122392026/09/10 03:42:58 INFO Uploading batch count=122402026/09/10 03:42:58 INFO Upload queue status pending=322412026/09/10 03:42:58 INFO Uploading batch count=122422026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=122432026/09/10 03:42:58 INFO Uploading batch count=422442026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=422452026/09/10 03:42:58 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-85886-2909774477/TestDrainIsolatesPoisonPath1123026479/002/bbb2246--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2247=== CONT TestQueueFetchRemoveLifecycle22482026/09/10 03:42:58 INFO Uploading batch count=122492026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=12250--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22512026/09/10 03:42:58 INFO Uploading batch count=122522026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=122532026/09/10 03:42:58 INFO Uploading batch count=122542026/09/10 03:42:58 ERROR Upload failed error="upload failed" count=122552026/09/10 03:42:58 ERROR Drain finished with paths left in queue remaining=12256--- PASS: TestDrainIsolatesPoisonPath (0.01s)2257--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2258--- PASS: TestWorkerUploadsAndRemoves (0.03s)2259--- PASS: TestWorkerSkipsGCdPaths (0.03s)2260--- PASS: TestWorkerPrunesClosureDeps (0.03s)2261--- PASS: TestQueueRemoveLargeClosure (0.05s)2262--- PASS: TestQueueConcurrentWriters (0.15s)22632026/09/10 03:42:58 ERROR Upload failed error="context deadline exceeded" count=222642026/09/10 03:42:58 ERROR Drain finished with paths left in queue remaining=42265--- PASS: TestDrainTimeout (0.21s)22662026/09/10 03:42:59 INFO Uploading batch count=122672026/09/10 03:42:59 INFO Uploading batch count=122682026/09/10 03:42:59 INFO Uploading batch count=122692026/09/10 03:42:59 ERROR Upload failed error="upload failed" count=122702026/09/10 03:42:59 INFO Uploading batch count=122712026/09/10 03:42:59 ERROR Upload failed error="upload failed" count=122722026/09/10 03:42:59 INFO Uploading batch count=122732026/09/10 03:42:59 ERROR Upload failed error="upload failed" count=122742026/09/10 03:42:59 INFO Uploading batch count=122752026/09/10 03:42:59 ERROR Upload failed error="upload failed" count=122762026/09/10 03:42:59 ERROR Drain finished with paths left in queue remaining=12277--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2278PASS