niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #191
· raw
1Running client tests...2=== RUN TestDumpPathCaseHackMatchesNix3=== RUN TestDumpPathCaseHackMatchesNix/collision4--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)5 --- PASS: TestDumpPathCaseHackMatchesNix/collision (0.00s)6=== RUN TestDoServerRequestAttachesToken7=== PAUSE TestDoServerRequestAttachesToken8=== RUN TestCaseHackSuffix9=== PAUSE TestCaseHackSuffix10=== RUN TestFilterOversizedClosures11=== PAUSE TestFilterOversizedClosures12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathMatchesNix17=== PAUSE TestDumpPathMatchesNix18=== RUN TestDumpPathSingleFile19=== PAUSE TestDumpPathSingleFile20=== RUN TestDumpPathWriterError21=== PAUSE TestDumpPathWriterError22=== RUN TestEncodeNixBase3223=== PAUSE TestEncodeNixBase3224=== RUN TestEncodeNixBase32WithRealHash25=== PAUSE TestEncodeNixBase32WithRealHash26=== RUN TestConvertHashToNix3227=== PAUSE TestConvertHashToNix3228=== RUN TestGetStorePathHash29=== PAUSE TestGetStorePathHash30=== RUN TestPathInfoHashCompatibility31=== PAUSE TestPathInfoHashCompatibility32=== RUN TestParsePathInfoJSON33=== PAUSE TestParsePathInfoJSON34=== RUN TestParsePathInfoJSONMultiplePaths35=== PAUSE TestParsePathInfoJSONMultiplePaths36=== RUN TestPathInfoCACompatibility37=== PAUSE TestPathInfoCACompatibility38=== RUN TestRateLimiterFeedback39=== PAUSE TestRateLimiterFeedback40=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess41=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== RUN TestResolveStorePath43=== PAUSE TestResolveStorePath44=== RUN TestDoWithRetry_BodyReplayedViaGetBody45=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody46=== RUN TestShellSplit47=== PAUSE TestShellSplit48=== RUN TestShellSplitErrors49=== PAUSE TestShellSplitErrors50=== RUN TestStreamPushReportsEveryPath51=== PAUSE TestStreamPushReportsEveryPath52=== RUN TestStreamPushBatchesUnderLoad53=== PAUSE TestStreamPushBatchesUnderLoad54=== RUN TestStreamPushIsolatesFailures55=== PAUSE TestStreamPushIsolatesFailures56=== RUN TestStreamPushGivesUpOnDeadServer57=== PAUSE TestStreamPushGivesUpOnDeadServer58=== RUN TestSetClientTLS59=== PAUSE TestSetClientTLS60=== RUN TestSetClientTLSDoesNotMutateDefaultTransport61=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport62=== RUN TestSetClientTLSErrors63=== PAUSE TestSetClientTLSErrors64=== RUN TestStaticToken65=== PAUSE TestStaticToken66=== RUN TestFileTokenReadsAndCaches67=== PAUSE TestFileTokenReadsAndCaches68=== RUN TestFileTokenMissing69=== PAUSE TestFileTokenMissing70=== RUN TestFileTokenEmpty71=== PAUSE TestFileTokenEmpty72=== RUN TestScriptTokenNoExpiryRerunsEveryCall73=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall74=== RUN TestScriptTokenCachesUntilRefresh75=== PAUSE TestScriptTokenCachesUntilRefresh76=== RUN TestScriptTokenEmptyToken77=== PAUSE TestScriptTokenEmptyToken78=== RUN TestScriptTokenBadJSON79=== PAUSE TestScriptTokenBadJSON80=== RUN TestScriptTokenScriptFails81=== PAUSE TestScriptTokenScriptFails82=== RUN TestScriptTokenEmptyCommand83=== PAUSE TestScriptTokenEmptyCommand84=== CONT TestDoServerRequestAttachesToken85=== CONT TestScriptTokenCachesUntilRefresh86=== CONT TestSetClientTLSDoesNotMutateDefaultTransport87=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess882026/09/10 12:33:54 WARN Rate limiter enabled after throttle name=server-test rate=589=== CONT TestScriptTokenNoExpiryRerunsEveryCall90=== CONT TestFileTokenEmpty91=== CONT TestFileTokenMissing92=== CONT TestFileTokenReadsAndCaches93=== CONT TestStaticToken94--- PASS: TestStaticToken (0.00s)95=== CONT TestEncodeNixBase32WithRealHash96--- PASS: TestEncodeNixBase32WithRealHash (0.00s)97=== CONT TestRateLimiterFeedback98=== RUN TestRateLimiterFeedback/429_enables_limiter99=== PAUSE TestRateLimiterFeedback/429_enables_limiter100=== CONT TestSetClientTLSErrors101=== RUN TestRateLimiterFeedback/503_enables_limiter102=== PAUSE TestRateLimiterFeedback/503_enables_limiter103=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter104=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter105=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter106=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter107=== CONT TestPathInfoCACompatibility108=== RUN TestPathInfoCACompatibility/null_ca_field109=== PAUSE TestPathInfoCACompatibility/null_ca_field110=== RUN TestPathInfoCACompatibility/old_string_format_-_text111=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text112=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive113=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive114=== RUN TestPathInfoCACompatibility/new_structured_format_-_text115=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text116=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method117=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method118=== CONT TestPathInfoHashCompatibility119--- PASS: TestFileTokenMissing (0.00s)120--- PASS: TestFileTokenEmpty (0.00s)121=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)122=== CONT TestParsePathInfoJSONMultiplePaths123=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths124=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths126=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)127=== CONT TestParsePathInfoJSON128=== RUN TestParsePathInfoJSON/Nix_format129=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths130=== CONT TestGetStorePathHash131=== RUN TestGetStorePathHash/valid_store_path132=== PAUSE TestGetStorePathHash/valid_store_path133=== PAUSE TestParsePathInfoJSON/Nix_format134=== RUN TestGetStorePathHash/basename_without_hyphen_should_error135=== RUN TestParsePathInfoJSON/Lix_format136=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error137=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error138=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error139=== PAUSE TestParsePathInfoJSON/Lix_format140=== RUN TestParsePathInfoJSON/empty_input141=== PAUSE TestParsePathInfoJSON/empty_input142=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error143=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error144=== CONT TestConvertHashToNix32145=== RUN TestConvertHashToNix32/SRI_format_to_Nix32146=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32147=== RUN TestConvertHashToNix32/already_Nix32_format148=== PAUSE TestConvertHashToNix32/already_Nix32_format149=== RUN TestConvertHashToNix32/invalid_format150=== RUN TestParsePathInfoJSON/whitespace_only151=== PAUSE TestConvertHashToNix32/invalid_format152=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon153=== CONT TestScriptTokenScriptFails154=== PAUSE TestParsePathInfoJSON/whitespace_only155=== RUN TestParsePathInfoJSON/invalid_JSON156=== RUN TestSetClientTLSErrors/missing_cert_file157=== PAUSE TestSetClientTLSErrors/missing_cert_file158=== RUN TestSetClientTLSErrors/missing_key_file159=== PAUSE TestSetClientTLSErrors/missing_key_file160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon161=== PAUSE TestParsePathInfoJSON/invalid_JSON162=== RUN TestSetClientTLSErrors/missing_ca_file163=== PAUSE TestSetClientTLSErrors/missing_ca_file164=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI165=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI166=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512167--- PASS: TestFileTokenReadsAndCaches (0.00s)168=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512169=== CONT TestScriptTokenEmptyCommand170--- PASS: TestScriptTokenEmptyCommand (0.00s)171=== CONT TestStreamPushGivesUpOnDeadServer172--- PASS: TestDoServerRequestAttachesToken (0.00s)173=== CONT TestSetClientTLS174=== RUN TestSetClientTLSErrors/invalid_ca_file175=== PAUSE TestSetClientTLSErrors/invalid_ca_file176=== CONT TestStreamPushIsolatesFailures177=== CONT TestStreamPushReportsEveryPath178=== CONT TestDumpPathMatchesNix1792026/09/10 12:33:54 ERROR Upload failed error="connection refused" count=201802026/09/10 12:33:54 ERROR Server seems unavailable, giving up on batch untried=171812026/09/10 12:33:54 ERROR Upload failed error="bad path" count=3182--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)183=== CONT TestStreamPushBatchesUnderLoad184--- PASS: TestStreamPushIsolatesFailures (0.00s)185=== CONT TestEncodeNixBase32186--- PASS: TestStreamPushReportsEveryPath (0.00s)187=== CONT TestDumpPathWriterError188=== RUN TestEncodeNixBase32/test_string_hash189=== PAUSE TestEncodeNixBase32/test_string_hash190=== RUN TestEncodeNixBase32/empty_input191=== PAUSE TestEncodeNixBase32/empty_input192=== CONT TestDumpPathSingleFile193--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)194=== CONT TestPartSizeForNAR195=== RUN TestPartSizeForNAR/zero_stays_at_minimum196=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum197=== RUN TestPartSizeForNAR/small_stays_at_minimum198=== PAUSE TestPartSizeForNAR/small_stays_at_minimum199=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum200=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum201=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts202=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts203=== RUN TestPartSizeForNAR/1_TiB204=== PAUSE TestPartSizeForNAR/1_TiB205=== RUN TestPartSizeForNAR/5_TiB_S3_max_object206=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object207=== RUN TestPartSizeForNAR/capped_at_5_GiB208=== PAUSE TestPartSizeForNAR/capped_at_5_GiB209=== CONT TestUploadMultipart_SupersededByPeer210=== RUN TestUploadMultipart_SupersededByPeer/exists211=== PAUSE TestUploadMultipart_SupersededByPeer/exists212=== RUN TestUploadMultipart_SupersededByPeer/missing213=== PAUSE TestUploadMultipart_SupersededByPeer/missing214=== CONT TestScriptTokenBadJSON215=== CONT TestShellSplit216=== CONT TestShellSplitErrors217--- PASS: TestScriptTokenScriptFails (0.00s)218--- PASS: TestShellSplit (0.00s)219--- PASS: TestShellSplitErrors (0.00s)220=== CONT TestDoWithRetry_BodyReplayedViaGetBody221=== RUN TestSetClientTLS/rejects_connection_without_client_cert222=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert223=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA224=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA225=== RUN TestSetClientTLS/preserves_debug_logging_transport226=== PAUSE TestSetClientTLS/preserves_debug_logging_transport227=== CONT TestFilterOversizedClosures228=== RUN TestFilterOversizedClosures/no_limit_keeps_everything229=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== RUN TestFilterOversizedClosures/all_closures_skipped233=== PAUSE TestFilterOversizedClosures/all_closures_skipped234=== CONT TestCaseHackSuffix2352026/09/10 12:33:54 WARN Rate limiter enabled after throttle name=server-test rate=52362026/09/10 12:33:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:652562372026/09/10 12:33:54 WARN Rate limiter backed off name=server-test rate=52382026/09/10 12:33:54 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65256239--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)240=== CONT TestResolveStorePath241--- PASS: TestResolveStorePath (0.00s)242=== CONT TestScriptTokenEmptyToken243--- PASS: TestScriptTokenBadJSON (0.01s)244=== CONT TestRateLimiterFeedback/429_enables_limiter2452026/09/10 12:33:54 WARN Rate limiter enabled after throttle name=server-test rate=52462026/09/10 12:33:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:652582472026/09/10 12:33:54 WARN Rate limiter backed off name=server-test rate=5248=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter249=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter250=== CONT TestRateLimiterFeedback/503_enables_limiter2512026/09/10 12:33:54 WARN Rate limiter enabled after throttle name=server-test rate=52522026/09/10 12:33:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:652642532026/09/10 12:33:54 WARN Rate limiter backed off name=server-test rate=5254--- PASS: TestRateLimiterFeedback (0.00s)255 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)256 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)257 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)258 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)259=== CONT TestPathInfoCACompatibility/null_ca_field260=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method261=== CONT TestPathInfoCACompatibility/new_structured_format_-_text262=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive263=== CONT TestPathInfoCACompatibility/old_string_format_-_text264--- PASS: TestPathInfoCACompatibility (0.00s)265 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)266 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)267 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)268 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)269 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)270=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths271=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths272--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)273 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)274 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)275=== 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--- PASS: TestGetStorePathHash (0.00s)280 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)281 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)282 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)283 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)284=== CONT TestConvertHashToNix32/SRI_format_to_Nix32285=== CONT TestConvertHashToNix32/invalid_format286=== CONT TestConvertHashToNix32/already_Nix32_format287--- PASS: TestConvertHashToNix32 (0.00s)288 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)289 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)290 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)291=== CONT TestParsePathInfoJSON/Nix_format292=== CONT TestParsePathInfoJSON/invalid_JSON293=== CONT TestParsePathInfoJSON/whitespace_only294=== CONT TestParsePathInfoJSON/empty_input295=== CONT TestParsePathInfoJSON/Lix_format296--- PASS: TestParsePathInfoJSON (0.00s)297 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)298 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)299 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)300 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)301 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)302=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)303=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI305=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon306--- PASS: TestPathInfoHashCompatibility (0.00s)307 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)308 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)309 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)310 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)311=== CONT TestSetClientTLSErrors/missing_cert_file312=== CONT TestSetClientTLSErrors/invalid_ca_file313=== CONT TestSetClientTLSErrors/missing_ca_file314=== CONT TestSetClientTLSErrors/missing_key_file315=== CONT TestEncodeNixBase32/test_string_hash316=== CONT TestEncodeNixBase32/empty_input317--- PASS: TestEncodeNixBase32 (0.00s)318 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)319 --- PASS: TestEncodeNixBase32/empty_input (0.00s)320=== CONT TestPartSizeForNAR/zero_stays_at_minimum321=== CONT TestPartSizeForNAR/1_TiB322=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum323=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts324=== CONT TestPartSizeForNAR/small_stays_at_minimum325=== CONT TestPartSizeForNAR/capped_at_5_GiB326=== CONT TestUploadMultipart_SupersededByPeer/exists327--- PASS: TestSetClientTLSErrors (0.00s)328 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)329 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)330 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)331 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)332--- PASS: TestScriptTokenEmptyToken (0.01s)333=== CONT TestUploadMultipart_SupersededByPeer/missing334=== CONT TestPartSizeForNAR/5_TiB_S3_max_object335--- PASS: TestPartSizeForNAR (0.00s)336 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)337 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)338 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)339 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)340 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)341 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)342 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)343=== CONT TestSetClientTLS/rejects_connection_without_client_cert344--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)347=== CONT TestSetClientTLS/preserves_debug_logging_transport348=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA349=== CONT TestFilterOversizedClosures/no_limit_keeps_everything350=== CONT TestFilterOversizedClosures/all_closures_skipped3512026/09/10 12:33:54 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=50352=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3532026/09/10 12:33:54 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=2000354--- PASS: TestFilterOversizedClosures (0.00s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)358--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)359--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)3602026/09/10 12:33:54 http: TLS handshake error from 127.0.0.1:65271: read tcp 127.0.0.1:65255->127.0.0.1:65271: use of closed network connection361--- PASS: TestSetClientTLS (0.01s)362 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)363 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)364 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)365--- PASS: TestDumpPathWriterError (0.04s)366--- PASS: TestDumpPathSingleFile (0.04s)367--- PASS: TestCaseHackSuffix (0.04s)368--- PASS: TestDumpPathMatchesNix (0.07s)369--- PASS: TestStreamPushBatchesUnderLoad (0.10s)370--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)371PASS372Running server tests...373The files belonging to this database system will be owned by user "_nixbld1".374This user must also own the server process.375376The database cluster will be initialized with locale "C".377The default database encoding has accordingly been set to "SQL_ASCII".378The default text search configuration will be set to "english".379380Data page checksums are enabled.381382creating directory /nix/var/nix/builds/nix-68052-3578224089/postgres2910017064/data ... ok383creating subdirectories ... ok384selecting dynamic shared memory implementation ... posix385selecting default "max_connections" ... 100386selecting default "shared_buffers" ... 128MB387selecting default time zone ... UTC388creating configuration files ... ok389running bootstrap script ... ok390performing post-bootstrap initialization ... ok391syncing data to disk ... ok392393initdb: warning: enabling "trust" authentication for local connections394initdb: 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.395396Success. You can now start the database server using:397398 pg_ctl -D /nix/var/nix/builds/nix-68052-3578224089/postgres2910017064/data -l logfile start399400/nix/var/nix/builds/nix-68052-3578224089/postgres2910017064:5432 - no response4012026-09-10 12:33:56.083 UTC [68089] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4022026-09-10 12:33:56.083 UTC [68089] LOG: listening on Unix socket "/nix/var/nix/builds/nix-68052-3578224089/postgres2910017064/.s.PGSQL.5432"4032026-09-10 12:33:56.086 UTC [68096] LOG: database system was shut down at 2026-09-10 12:33:56 UTC4042026-09-10 12:33:56.086 UTC [68089] LOG: database system is ready to accept connections405/nix/var/nix/builds/nix-68052-3578224089/postgres2910017064:5432 - accepting connections406=== RUN TestService_AuthMiddleware407=== PAUSE TestService_AuthMiddleware408=== RUN TestService_AuthMiddleware_MTLSProxyHeader409=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader410=== RUN TestService_AuthMiddleware_MTLSBoundSubjects411=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects412=== RUN TestService_ReadAuthMiddleware413=== PAUSE TestService_ReadAuthMiddleware414=== RUN TestService_AuthMiddleware_OIDC415=== PAUSE TestService_AuthMiddleware_OIDC416=== RUN TestService_RequireScope_OIDC417=== PAUSE TestService_RequireScope_OIDC418=== RUN TestService_ReadScope_PublicByDefault419=== PAUSE TestService_ReadScope_PublicByDefault420=== RUN TestCacheConfigHandler421=== PAUSE TestCacheConfigHandler422=== RUN TestCacheStatsHandler423=== PAUSE TestCacheStatsHandler424=== RUN TestClientCADerivations425=== PAUSE TestClientCADerivations426=== RUN TestClientErrorHandling427=== PAUSE TestClientErrorHandling428=== RUN TestClientIntegration429=== PAUSE TestClientIntegration430=== RUN TestClientMultipleUploads431=== PAUSE TestClientMultipleUploads432=== RUN TestClientWithDependencies433=== PAUSE TestClientWithDependencies434=== RUN TestPinProtectsFromGC435=== PAUSE TestPinProtectsFromGC436=== RUN TestResolveDBConnectionString437=== PAUSE TestResolveDBConnectionString438=== RUN TestGCAdvisoryLockBlocksConcurrentRun4392026-09-10 12:33:56.493 UTC [68168] ERROR: relation "goose_db_version" does not exist at character 364402026-09-10 12:33:56.493 UTC [68168] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4412026/09/10 12:33:56 OK 20241026095416_initial_model.sql (3.53ms)4422026/09/10 12:33:56 OK 20251210153512_drop_unused_gin_index.sql (524.83µs)4432026/09/10 12:33:56 OK 20251218171726_add_pins.sql (887.17µs)4442026/09/10 12:33:56 OK 20260628120000_add_object_size_and_stats.sql (834.83µs)4452026/09/10 12:33:56 goose: successfully migrated database to version: 202606281200004462026/09/10 12:33:56 OK 1_commit_pending_closure.sql (966.21µs)4472026/09/10 12:33:56 OK 2_object_stats_trigger.sql (218.21µs)4482026/09/10 12:33:56 goose: up to current file version: 2449--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.26s)450=== RUN TestGCBugBareHashReferences451=== PAUSE TestGCBugBareHashReferences452=== RUN TestGCMetrics453=== PAUSE TestGCMetrics454=== RUN TestGCTaskStore_StartNew455=== PAUSE TestGCTaskStore_StartNew456=== RUN TestGCTaskStore_DeduplicateSameParams457=== PAUSE TestGCTaskStore_DeduplicateSameParams458=== RUN TestGCTaskStore_ConflictDifferentParams459=== PAUSE TestGCTaskStore_ConflictDifferentParams460=== RUN TestGCTaskStore_GetEmpty461=== PAUSE TestGCTaskStore_GetEmpty462=== RUN TestGCTaskStore_GetReturnsLatest463=== PAUSE TestGCTaskStore_GetReturnsLatest464=== RUN TestGCTaskStore_CompletedAllowsNewTask465=== PAUSE TestGCTaskStore_CompletedAllowsNewTask466=== RUN TestGCTaskStore_PhaseUpdates467=== PAUSE TestGCTaskStore_PhaseUpdates468=== RUN TestGCTaskStore_Fail469=== PAUSE TestGCTaskStore_Fail470=== RUN TestGracefulShutdownDrainsInflight471=== PAUSE TestGracefulShutdownDrainsInflight472=== RUN TestService_healthCheckHandler473=== PAUSE TestService_healthCheckHandler474=== RUN TestService_readinessHandler475=== PAUSE TestService_readinessHandler476=== RUN TestGenerateLandingPage477=== PAUSE TestGenerateLandingPage478=== RUN TestCacheConfigHandlerMaxNarSize479=== PAUSE TestCacheConfigHandlerMaxNarSize480=== RUN TestCreatePendingClosureRejectsOversizedNAR481=== PAUSE TestCreatePendingClosureRejectsOversizedNAR482=== RUN TestNARDeduplicationMetadataUploadBug483=== PAUSE TestNARDeduplicationMetadataUploadBug484=== RUN TestMetricsInventory485=== PAUSE TestMetricsInventory486=== RUN TestService_NativeMTLS487=== PAUSE TestService_NativeMTLS488=== RUN TestServerTLSConfig489=== PAUSE TestServerTLSConfig490=== RUN TestMultipartCleanup491=== PAUSE TestMultipartCleanup492=== RUN TestObjectStatsTrigger493=== PAUSE TestObjectStatsTrigger494=== RUN TestOrphanedObjectsGC495=== PAUSE TestOrphanedObjectsGC496=== RUN TestOrphanedObjectsGCStressTest497=== PAUSE TestOrphanedObjectsGCStressTest498=== RUN TestResurrectedObjectNotDeleted499=== PAUSE TestResurrectedObjectNotDeleted500=== RUN TestParseSingleRange501=== PAUSE TestParseSingleRange502=== RUN TestIsValidCachePath503=== PAUSE TestIsValidCachePath504=== RUN TestReadProxyNarinfo505=== PAUSE TestReadProxyNarinfo506=== RUN TestReadProxyNarinfoAlreadyDecompressed507=== PAUSE TestReadProxyNarinfoAlreadyDecompressed508=== RUN TestReadProxyNarStreaming509=== PAUSE TestReadProxyNarStreaming510=== RUN TestReadProxy404511=== PAUSE TestReadProxy404512=== RUN TestReadProxyInvalidPath513=== PAUSE TestReadProxyInvalidPath514=== RUN TestReadProxyHead515=== PAUSE TestReadProxyHead516=== RUN TestReadProxyConditionalGet517=== PAUSE TestReadProxyConditionalGet518=== RUN TestReadProxyRootRedirectsToIndexHTML519=== PAUSE TestReadProxyRootRedirectsToIndexHTML520=== RUN TestReadProxyDisabled521=== PAUSE TestReadProxyDisabled522=== RUN TestReadRedirectNar523=== PAUSE TestReadRedirectNar524=== RUN TestReadRedirectKeepsNarinfoProxied525=== PAUSE TestReadRedirectKeepsNarinfoProxied526=== RUN TestReadProxyRangeRequest527=== PAUSE TestReadProxyRangeRequest528=== RUN TestReadRedirectUsesPublicS3URL529=== PAUSE TestReadRedirectUsesPublicS3URL530=== RUN TestRedundantMultipartUpload531=== PAUSE TestRedundantMultipartUpload532=== RUN TestCompleteMultipartUpload_ErrorButObjectExists533=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists534=== RUN TestCompletedNarNotReofferedAcrossClosures535=== PAUSE TestCompletedNarNotReofferedAcrossClosures536=== RUN TestPresignedUploadRegisteredBeforeCommit537=== PAUSE TestPresignedUploadRegisteredBeforeCommit538=== RUN TestService_Rustfstest539=== PAUSE TestService_Rustfstest540=== RUN TestParseSize541=== PAUSE TestParseSize542=== RUN TestSkippedUploadsHandler543=== PAUSE TestSkippedUploadsHandler544=== RUN TestSystemdListenerNotActivated545--- PASS: TestSystemdListenerNotActivated (0.00s)546=== RUN TestWatchdogBeatsWhenHealthy547--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)548=== RUN TestWatchdogSkipsWhenUnhealthy5492026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5502026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5512026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5522026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5532026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5542026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5552026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5562026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5572026/09/10 12:33:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"558--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)559=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle560=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle561=== RUN TestProxyWriteTimeout562=== PAUSE TestProxyWriteTimeout563=== RUN TestIsValidUploadKey564=== PAUSE TestIsValidUploadKey565=== RUN TestUploadHandlersRejectInvalidKeys566=== PAUSE TestUploadHandlersRejectInvalidKeys567=== RUN TestUploadHandlersRejectOversizedBody568=== PAUSE TestUploadHandlersRejectOversizedBody569=== RUN TestService_cleanupPendingClosuresHandler570=== PAUSE TestService_cleanupPendingClosuresHandler571=== RUN TestService_createPendingClosureHandler572=== PAUSE TestService_createPendingClosureHandler573=== RUN TestService_verifyS3Integrity574=== PAUSE TestService_verifyS3Integrity575=== RUN TestCompleteMultipartUnregistered576=== PAUSE TestCompleteMultipartUnregistered577=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT578=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT579=== CONT TestReadRedirectUsesPublicS3URL580=== CONT TestService_AuthMiddleware581=== CONT TestService_readinessHandler582=== CONT TestProxyWriteTimeout583=== CONT TestService_createPendingClosureHandler584=== CONT TestCompleteMultipartUnregistered585=== RUN TestProxyWriteTimeout/narinfo586=== PAUSE TestProxyWriteTimeout/narinfo587=== RUN TestProxyWriteTimeout/1_GiB_nar588=== PAUSE TestProxyWriteTimeout/1_GiB_nar589=== RUN TestProxyWriteTimeout/10_GiB_nar590=== PAUSE TestProxyWriteTimeout/10_GiB_nar591=== RUN TestProxyWriteTimeout/unknown_size592=== PAUSE TestProxyWriteTimeout/unknown_size593=== CONT TestService_cleanupPendingClosuresHandler594=== CONT TestService_verifyS3Integrity595=== CONT TestUploadHandlersRejectOversizedBody596=== CONT TestUploadHandlersRejectInvalidKeys597=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info598=== CONT TestIsValidUploadKey599=== RUN TestIsValidUploadKey/narinfo600=== PAUSE TestIsValidUploadKey/narinfo601=== RUN TestIsValidUploadKey/nar_zst602=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info603=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal604=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal605=== PAUSE TestIsValidUploadKey/nar_zst606=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key607=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key608=== RUN TestIsValidUploadKey/nar_xz609=== PAUSE TestIsValidUploadKey/nar_xz610=== RUN TestIsValidUploadKey/nar_plain611=== PAUSE TestIsValidUploadKey/nar_plain612=== RUN TestIsValidUploadKey/listing613=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key614=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key615=== PAUSE TestIsValidUploadKey/listing616=== RUN TestIsValidUploadKey/build_log617=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT618=== PAUSE TestIsValidUploadKey/build_log619=== RUN TestIsValidUploadKey/build_log_home-manager_file620=== PAUSE TestIsValidUploadKey/build_log_home-manager_file621=== RUN TestIsValidUploadKey/build_log_plus_in_name622=== PAUSE TestIsValidUploadKey/build_log_plus_in_name623=== RUN TestIsValidUploadKey/build_log_question_mark624=== PAUSE TestIsValidUploadKey/build_log_question_mark625=== RUN TestIsValidUploadKey/build_log_equals626=== PAUSE TestIsValidUploadKey/build_log_equals627=== RUN TestIsValidUploadKey/realisation628=== PAUSE TestIsValidUploadKey/realisation629=== RUN TestIsValidUploadKey/realisation_plus_in_output630=== PAUSE TestIsValidUploadKey/realisation_plus_in_output631=== RUN TestIsValidUploadKey/nix-cache-info632=== PAUSE TestIsValidUploadKey/nix-cache-info633=== RUN TestIsValidUploadKey/index.html634=== PAUSE TestIsValidUploadKey/index.html635=== RUN TestIsValidUploadKey/narinfo_key,_nar_type636=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type637=== RUN TestIsValidUploadKey/nar_key,_narinfo_type638=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type639=== RUN TestIsValidUploadKey/listing_key,_narinfo_type640=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type641=== RUN TestIsValidUploadKey/traversal642=== PAUSE TestIsValidUploadKey/traversal643=== RUN TestIsValidUploadKey/traversal_nar644=== PAUSE TestIsValidUploadKey/traversal_nar645=== RUN TestIsValidUploadKey/absolute646=== PAUSE TestIsValidUploadKey/absolute647=== RUN TestIsValidUploadKey/empty_key648=== PAUSE TestIsValidUploadKey/empty_key649=== RUN TestIsValidUploadKey/unknown_type650=== PAUSE TestIsValidUploadKey/unknown_type651=== CONT TestPinProtectsFromGC652=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure653=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure654=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart655=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart656=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts657=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts658=== CONT TestService_healthCheckHandler6592026-09-10 12:33:57.114 UTC [68190] ERROR: relation "goose_db_version" does not exist at character 366602026-09-10 12:33:57.114 UTC [68190] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6612026/09/10 12:33:57 OK 20241026095416_initial_model.sql (23.87ms)6622026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)6632026-09-10 12:33:57.151 UTC [68191] ERROR: relation "goose_db_version" does not exist at character 366642026-09-10 12:33:57.151 UTC [68191] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-09-10 12:33:57.152 UTC [68193] ERROR: relation "goose_db_version" does not exist at character 366662026-09-10 12:33:57.152 UTC [68193] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026/09/10 12:33:57 OK 20251218171726_add_pins.sql (1.7ms)6682026-09-10 12:33:57.153 UTC [68192] ERROR: relation "goose_db_version" does not exist at character 366692026-09-10 12:33:57.153 UTC [68192] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6702026-09-10 12:33:57.153 UTC [68194] ERROR: relation "goose_db_version" does not exist at character 366712026-09-10 12:33:57.153 UTC [68194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6722026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (1.23ms)6732026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200006742026-09-10 12:33:57.154 UTC [68196] ERROR: relation "goose_db_version" does not exist at character 366752026-09-10 12:33:57.154 UTC [68196] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6762026-09-10 12:33:57.154 UTC [68195] ERROR: relation "goose_db_version" does not exist at character 366772026-09-10 12:33:57.154 UTC [68195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6782026-09-10 12:33:57.155 UTC [68197] ERROR: relation "goose_db_version" does not exist at character 366792026-09-10 12:33:57.155 UTC [68197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6802026-09-10 12:33:57.156 UTC [68198] ERROR: relation "goose_db_version" does not exist at character 366812026-09-10 12:33:57.156 UTC [68198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6822026-09-10 12:33:57.156 UTC [68199] ERROR: relation "goose_db_version" does not exist at character 366832026-09-10 12:33:57.156 UTC [68199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026/09/10 12:33:57 OK 1_commit_pending_closure.sql (2.21ms)6852026/09/10 12:33:57 OK 2_object_stats_trigger.sql (568.88µs)6862026/09/10 12:33:57 goose: up to current file version: 26872026/09/10 12:33:57 OK 20241026095416_initial_model.sql (28.72ms)6882026/09/10 12:33:57 OK 20241026095416_initial_model.sql (28.59ms)6892026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (7.11ms)6902026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (7.1ms)6912026/09/10 12:33:57 OK 20241026095416_initial_model.sql (39.15ms)6922026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (8.87ms)6932026/09/10 12:33:57 OK 20251218171726_add_pins.sql (11.77ms)6942026/09/10 12:33:57 OK 20241026095416_initial_model.sql (46.79ms)6952026/09/10 12:33:57 OK 20251218171726_add_pins.sql (12.57ms)6962026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (927.63µs)6972026/09/10 12:33:57 OK 20251218171726_add_pins.sql (2.3ms)6982026/09/10 12:33:57 OK 20241026095416_initial_model.sql (46.36ms)6992026/09/10 12:33:57 OK 20241026095416_initial_model.sql (49.76ms)7002026/09/10 12:33:57 OK 20241026095416_initial_model.sql (49.74ms)7012026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (5ms)7022026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007032026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (8.34ms)7042026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (9.55ms)7052026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007062026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (8.65ms)7072026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007082026/09/10 12:33:57 OK 20241026095416_initial_model.sql (45.82ms)7092026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (5.96ms)7102026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (5.94ms)7112026/09/10 12:33:57 OK 20251218171726_add_pins.sql (10.22ms)7122026/09/10 12:33:57 OK 1_commit_pending_closure.sql (6.25ms)7132026/09/10 12:33:57 OK 20241026095416_initial_model.sql (56.72ms)7142026/09/10 12:33:57 OK 2_object_stats_trigger.sql (288.58µs)7152026/09/10 12:33:57 goose: up to current file version: 27162026/09/10 12:33:57 OK 1_commit_pending_closure.sql (1.52ms)7172026/09/10 12:33:57 OK 1_commit_pending_closure.sql (1.52ms)7182026/09/10 12:33:57 OK 2_object_stats_trigger.sql (185.88µs)7192026/09/10 12:33:57 goose: up to current file version: 27202026/09/10 12:33:57 OK 2_object_stats_trigger.sql (197.75µs)7212026/09/10 12:33:57 goose: up to current file version: 27222026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (7.82ms)7232026/09/10 12:33:57 OK 20251210153512_drop_unused_gin_index.sql (7.78ms)7242026/09/10 12:33:57 OK 20251218171726_add_pins.sql (9.29ms)7252026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (9.91ms)7262026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007272026/09/10 12:33:57 OK 20251218171726_add_pins.sql (2.86ms)7282026/09/10 12:33:57 OK 20251218171726_add_pins.sql (10.23ms)7292026/09/10 12:33:57 OK 20251218171726_add_pins.sql (10.25ms)7302026/09/10 12:33:57 OK 20251218171726_add_pins.sql (2.16ms)7312026/09/10 12:33:57 OK 1_commit_pending_closure.sql (912.67µs)7322026/09/10 12:33:57 OK 2_object_stats_trigger.sql (207.67µs)7332026/09/10 12:33:57 goose: up to current file version: 27342026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (10.73ms)7352026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007362026/09/10 12:33:57 OK 1_commit_pending_closure.sql (1.62ms)7372026/09/10 12:33:57 OK 2_object_stats_trigger.sql (234.67µs)7382026/09/10 12:33:57 goose: up to current file version: 27392026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (16.24ms)7402026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007412026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (16.4ms)7422026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007432026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (16.42ms)7442026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007452026/09/10 12:33:57 OK 20260628120000_add_object_size_and_stats.sql (16.38ms)7462026/09/10 12:33:57 goose: successfully migrated database to version: 202606281200007472026/09/10 12:33:57 OK 1_commit_pending_closure.sql (965.67µs)7482026/09/10 12:33:57 OK 1_commit_pending_closure.sql (973.42µs)7492026/09/10 12:33:57 OK 1_commit_pending_closure.sql (1.05ms)7502026/09/10 12:33:57 OK 1_commit_pending_closure.sql (1.11ms)7512026/09/10 12:33:57 OK 2_object_stats_trigger.sql (266.58µs)7522026/09/10 12:33:57 goose: up to current file version: 27532026/09/10 12:33:57 OK 2_object_stats_trigger.sql (248.17µs)7542026/09/10 12:33:57 goose: up to current file version: 27552026/09/10 12:33:57 OK 2_object_stats_trigger.sql (226.08µs)7562026/09/10 12:33:57 goose: up to current file version: 27572026/09/10 12:33:57 OK 2_object_stats_trigger.sql (203.71µs)7582026/09/10 12:33:57 goose: up to current file version: 2759--- PASS: TestReadRedirectUsesPublicS3URL (0.48s)760=== CONT TestGracefulShutdownDrainsInflight7612026/09/10 12:33:57 INFO Starting HTTP server address=127.0.0.1:652917622026/09/10 12:33:57 INFO Shutdown signal received, draining in-flight requests timeout=10s763--- PASS: TestGracefulShutdownDrainsInflight (0.07s)764=== CONT TestGCTaskStore_Fail765--- PASS: TestGCTaskStore_Fail (0.00s)766=== CONT TestGCTaskStore_PhaseUpdates767--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)768=== CONT TestGCTaskStore_CompletedAllowsNewTask769--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)770=== CONT TestGCTaskStore_GetReturnsLatest771--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)772=== CONT TestGCTaskStore_GetEmpty773--- PASS: TestGCTaskStore_GetEmpty (0.00s)774=== CONT TestGCTaskStore_ConflictDifferentParams775--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)776=== CONT TestGCTaskStore_DeduplicateSameParams777--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)778=== CONT TestGCTaskStore_StartNew779--- PASS: TestGCTaskStore_StartNew (0.00s)780=== CONT TestGCMetrics7812026/09/10 12:33:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"782--- PASS: TestService_AuthMiddleware (0.59s)783=== CONT TestGCBugBareHashReferences7842026/09/10 12:33:57 INFO Received uploads request method=POST path=/api/pending_closures7852026/09/10 12:33:57 INFO Received uploads request method=POST path=/api/pending_closures7862026/09/10 12:33:57 INFO Received uploads request method=POST path=/api/pending_closures7872026/09/10 12:33:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7882026/09/10 12:33:57 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst789--- PASS: TestCompleteMultipartUnregistered (0.89s)790=== CONT TestResolveDBConnectionString791=== RUN TestResolveDBConnectionString/flag_wins792=== PAUSE TestResolveDBConnectionString/flag_wins793=== RUN TestResolveDBConnectionString/file_when_flag_empty794=== PAUSE TestResolveDBConnectionString/file_when_flag_empty795=== RUN TestResolveDBConnectionString/missing_file_is_an_error796=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error797=== RUN TestResolveDBConnectionString/PGHOST_allows_empty798=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty799=== RUN TestResolveDBConnectionString/nothing_configured800=== PAUSE TestResolveDBConnectionString/nothing_configured801=== CONT TestIsValidCachePath802=== RUN TestIsValidCachePath/narinfo803=== PAUSE TestIsValidCachePath/narinfo804=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars805=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars806=== RUN TestIsValidCachePath/nar_zst807=== PAUSE TestIsValidCachePath/nar_zst808=== RUN TestIsValidCachePath/nar_xz809=== PAUSE TestIsValidCachePath/nar_xz810=== RUN TestIsValidCachePath/nar_bz2811=== PAUSE TestIsValidCachePath/nar_bz2812=== RUN TestIsValidCachePath/nar_uncompressed813=== PAUSE TestIsValidCachePath/nar_uncompressed814=== RUN TestIsValidCachePath/ls815=== PAUSE TestIsValidCachePath/ls816=== RUN TestIsValidCachePath/log817=== PAUSE TestIsValidCachePath/log818=== RUN TestIsValidCachePath/realisation819=== PAUSE TestIsValidCachePath/realisation820=== RUN TestIsValidCachePath/nix-cache-info821=== PAUSE TestIsValidCachePath/nix-cache-info822=== RUN TestIsValidCachePath/index.html823=== PAUSE TestIsValidCachePath/index.html824=== RUN TestIsValidCachePath/traversal_parent825=== PAUSE TestIsValidCachePath/traversal_parent826=== RUN TestIsValidCachePath/traversal_in_middle827=== PAUSE TestIsValidCachePath/traversal_in_middle828=== RUN TestIsValidCachePath/invalid_char_e829=== PAUSE TestIsValidCachePath/invalid_char_e830=== RUN TestIsValidCachePath/invalid_char_u831=== PAUSE TestIsValidCachePath/invalid_char_u832=== RUN TestIsValidCachePath/random_path833=== PAUSE TestIsValidCachePath/random_path834=== RUN TestIsValidCachePath/empty835=== PAUSE TestIsValidCachePath/empty836=== RUN TestIsValidCachePath/leading_slash837=== PAUSE TestIsValidCachePath/leading_slash838=== RUN TestIsValidCachePath/wrong_extension839=== PAUSE TestIsValidCachePath/wrong_extension840=== RUN TestIsValidCachePath/short_hash841=== PAUSE TestIsValidCachePath/short_hash842=== CONT TestReadProxyRangeRequest8432026/09/10 12:33:57 WARN readiness check failed error="closed pool"844--- PASS: TestService_readinessHandler (1.07s)845=== CONT TestReadRedirectKeepsNarinfoProxied8462026-09-10 12:33:58.193 UTC [68209] ERROR: relation "goose_db_version" does not exist at character 368472026-09-10 12:33:58.193 UTC [68209] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026-09-10 12:33:58.201 UTC [68210] ERROR: relation "goose_db_version" does not exist at character 368492026-09-10 12:33:58.201 UTC [68210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/09/10 12:33:58 INFO Received uploads request method=POST path=/api/pending_closures851--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.51s)852=== CONT TestReadRedirectNar8532026/09/10 12:33:58 OK 20241026095416_initial_model.sql (102.37ms)8542026/09/10 12:33:58 OK 20241026095416_initial_model.sql (102.69ms)8552026/09/10 12:33:58 OK 20251210153512_drop_unused_gin_index.sql (738.96µs)8562026/09/10 12:33:58 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)8572026/09/10 12:33:58 OK 20251218171726_add_pins.sql (19.66ms)8582026/09/10 12:33:58 OK 20251218171726_add_pins.sql (20.97ms)859=== NAME TestPinProtectsFromGC860 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-68052-3578224089/TestPinProtectsFromGC3560828093/001/store/nrpjbmz2wkslm28b7s1j2sa5vsk904fs-pinned-file.txt861 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-68052-3578224089/TestPinProtectsFromGC3560828093/001/store/0yknc8ipky7v2hzndj7x7qyx74lhsrgr-unpinned-file.txt8622026/09/10 12:33:58 OK 20260628120000_add_object_size_and_stats.sql (26.39ms)8632026/09/10 12:33:58 goose: successfully migrated database to version: 202606281200008642026/09/10 12:33:58 OK 20260628120000_add_object_size_and_stats.sql (32.46ms)8652026/09/10 12:33:58 goose: successfully migrated database to version: 202606281200008662026/09/10 12:33:58 OK 1_commit_pending_closure.sql (6.8ms)8672026/09/10 12:33:58 OK 2_object_stats_trigger.sql (233.42µs)8682026/09/10 12:33:58 goose: up to current file version: 28692026/09/10 12:33:58 OK 1_commit_pending_closure.sql (1.41ms)8702026/09/10 12:33:58 OK 2_object_stats_trigger.sql (197µs)8712026/09/10 12:33:58 goose: up to current file version: 28722026/09/10 12:33:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8732026-09-10 12:33:58.440 UTC [68220] ERROR: relation "goose_db_version" does not exist at character 368742026-09-10 12:33:58.440 UTC [68220] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026/09/10 12:33:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8762026/09/10 12:33:58 INFO Received uploads request method=POST path=/api/pending_closures8772026/09/10 12:33:58 INFO Received uploads request method=POST path=/api/pending_closures8782026/09/10 12:33:58 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDA1ZjE5YmUtNmUwZC00YTNiLWFiNmItOGQ3ZjU1ZDkwZmVmLjVlMmEwOWI5LWVlZDAtNDIzNi04NGQwLTNlZjEwNWI1NzExMngxNzg5MDQzNjM3NTMwMDcyMDAw parts=108792026/09/10 12:33:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8802026/09/10 12:33:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8812026/09/10 12:33:58 INFO Uploading nrpjbmz2wkslm28b7s1j2sa5vsk904fs-pinned-file.txt (128B)8822026/09/10 12:33:58 INFO Completed upload id=18832026/09/10 12:33:58 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008842026/09/10 12:33:58 INFO Received uploads request method=POST path=/api/pending_closures8852026/09/10 12:33:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures8862026/09/10 12:33:58 INFO Aborted multipart uploads count=08872026/09/10 12:33:58 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=08882026/09/10 12:33:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"8892026/09/10 12:33:58 INFO Vacuumed table table=pending_closures8902026/09/10 12:33:58 INFO Vacuumed table table=pending_objects8912026/09/10 12:33:58 INFO Vacuumed table table=multipart_uploads8922026/09/10 12:33:58 WARN Failed to register uploaded object key=nrpjbmz2wkslm28b7s1j2sa5vsk904fs.ls error="server returned 404: 404 page not found\n"8932026/09/10 12:33:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8942026/09/10 12:33:58 INFO Signed narinfos id=1 count=18952026/09/10 12:33:58 INFO Uploading 1 narinfos8962026/09/10 12:33:58 WARN Failed to register uploaded object key=nrpjbmz2wkslm28b7s1j2sa5vsk904fs.narinfo error="server returned 404: 404 page not found\n"8972026/09/10 12:33:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8982026/09/10 12:33:58 OK 20241026095416_initial_model.sql (58.03ms)8992026/09/10 12:33:58 INFO Vacuumed table table=closures9002026/09/10 12:33:58 OK 20251210153512_drop_unused_gin_index.sql (5.8ms)9012026/09/10 12:33:58 INFO Completed upload id=19022026/09/10 12:33:58 INFO Upload complete. (156ms)9032026/09/10 12:33:58 INFO Vacuumed table table=objects9042026/09/10 12:33:58 OK 20251218171726_add_pins.sql (12.08ms)9052026/09/10 12:33:58 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000906--- PASS: TestService_createPendingClosureHandler (1.77s)907=== CONT TestReadProxyDisabled9082026/09/10 12:33:58 OK 20260628120000_add_object_size_and_stats.sql (27.69ms)9092026/09/10 12:33:58 goose: successfully migrated database to version: 202606281200009102026/09/10 12:33:58 OK 1_commit_pending_closure.sql (7.4ms)9112026/09/10 12:33:58 OK 2_object_stats_trigger.sql (250.29µs)9122026/09/10 12:33:58 goose: up to current file version: 29132026/09/10 12:33:58 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9142026-09-10 12:33:58.622 UTC [68231] ERROR: relation "goose_db_version" does not exist at character 369152026-09-10 12:33:58.622 UTC [68231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9162026/09/10 12:33:58 INFO Received uploads request method=POST path=/api/pending_closures9172026/09/10 12:33:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9182026/09/10 12:33:58 INFO Uploading 0yknc8ipky7v2hzndj7x7qyx74lhsrgr-unpinned-file.txt (128B)9192026/09/10 12:33:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"920--- PASS: TestService_healthCheckHandler (1.83s)921=== CONT TestReadProxyRootRedirectsToIndexHTML9222026/09/10 12:33:58 WARN Failed to register uploaded object key=0yknc8ipky7v2hzndj7x7qyx74lhsrgr.ls error="server returned 404: 404 page not found\n"9232026/09/10 12:33:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9242026/09/10 12:33:58 INFO Signed narinfos id=2 count=19252026/09/10 12:33:58 INFO Uploading 1 narinfos9262026/09/10 12:33:58 WARN Failed to register uploaded object key=0yknc8ipky7v2hzndj7x7qyx74lhsrgr.narinfo error="server returned 404: 404 page not found\n"9272026/09/10 12:33:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9282026/09/10 12:33:58 INFO Completed upload id=29292026/09/10 12:33:58 INFO Upload complete. (125ms)9302026/09/10 12:33:58 INFO Received create pin request method=POST path=/api/pins/myapp9312026/09/10 12:33:58 OK 20241026095416_initial_model.sql (110.12ms)9322026/09/10 12:33:58 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-68052-3578224089/TestPinProtectsFromGC3560828093/001/store/nrpjbmz2wkslm28b7s1j2sa5vsk904fs-pinned-file.txt narinfo_key=nrpjbmz2wkslm28b7s1j2sa5vsk904fs.narinfo9332026/09/10 12:33:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures9342026/09/10 12:33:58 INFO Garbage collection started9352026/09/10 12:33:58 INFO Aborted multipart uploads count=09362026/09/10 12:33:58 WARN Force mode enabled - objects will be deleted immediately without grace period9372026/09/10 12:33:58 OK 20251210153512_drop_unused_gin_index.sql (6.64ms)9382026/09/10 12:33:58 OK 20251218171726_add_pins.sql (12.77ms)9392026/09/10 12:33:58 OK 20260628120000_add_object_size_and_stats.sql (17.17ms)9402026/09/10 12:33:58 goose: successfully migrated database to version: 202606281200009412026/09/10 12:33:58 OK 1_commit_pending_closure.sql (6.79ms)9422026/09/10 12:33:58 OK 2_object_stats_trigger.sql (218.13µs)9432026/09/10 12:33:58 goose: up to current file version: 29442026/09/10 12:33:58 INFO Received cleanup request method=DELETE path=/api/pending_closures9452026/09/10 12:33:58 INFO Aborted multipart uploads count=09462026/09/10 12:33:58 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/10 12:33:58 INFO Received cleanup request method=DELETE path=/api/pending_closures9482026/09/10 12:33:58 INFO Aborted multipart uploads count=19492026/09/10 12:33:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9502026-09-10 12:33:58.917 UTC [68198] ERROR: Closure does not exist: id=19512026-09-10 12:33:58.917 UTC [68198] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9522026-09-10 12:33:58.917 UTC [68198] STATEMENT: -- name: CommitPendingClosure :exec953 SELECT commit_pending_closure($1::bigint)954 955--- PASS: TestService_cleanupPendingClosuresHandler (2.13s)956=== CONT TestReadProxyConditionalGet9572026/09/10 12:33:58 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=09582026/09/10 12:33:59 INFO Vacuumed table table=pending_closures9592026/09/10 12:33:59 INFO Vacuumed table table=pending_objects9602026/09/10 12:33:59 INFO Vacuumed table table=multipart_uploads9612026/09/10 12:33:59 INFO Vacuumed table table=closures9622026/09/10 12:33:59 INFO Vacuumed table table=objects9632026/09/10 12:33:59 INFO Aborted multipart uploads count=09642026/09/10 12:33:59 WARN Force mode enabled - objects will be deleted immediately without grace period9652026/09/10 12:33:59 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=09662026/09/10 12:33:59 INFO Vacuumed table table=pending_closures9672026/09/10 12:33:59 INFO Vacuumed table table=pending_objects9682026/09/10 12:33:59 INFO Vacuumed table table=multipart_uploads9692026/09/10 12:33:59 INFO Vacuumed table table=closures9702026-09-10 12:33:59.077 UTC [68242] ERROR: relation "goose_db_version" does not exist at character 369712026-09-10 12:33:59.077 UTC [68242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9722026/09/10 12:33:59 INFO Vacuumed table table=objects973--- PASS: TestGCMetrics (1.73s)974=== CONT TestReadProxyHead9752026/09/10 12:33:59 OK 20241026095416_initial_model.sql (96.55ms)9762026/09/10 12:33:59 OK 20251210153512_drop_unused_gin_index.sql (12.02ms)9772026/09/10 12:33:59 OK 20251218171726_add_pins.sql (13.09ms)9782026/09/10 12:33:59 OK 20260628120000_add_object_size_and_stats.sql (26.02ms)9792026/09/10 12:33:59 goose: successfully migrated database to version: 202606281200009802026/09/10 12:33:59 OK 1_commit_pending_closure.sql (11.68ms)9812026/09/10 12:33:59 OK 2_object_stats_trigger.sql (344µs)9822026/09/10 12:33:59 goose: up to current file version: 2983--- PASS: TestReadProxyRangeRequest (1.72s)984=== CONT TestReadProxyInvalidPath9852026/09/10 12:33:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9862026/09/10 12:33:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDA1ZjE5YmUtNmUwZC00YTNiLWFiNmItOGQ3ZjU1ZDkwZmVmLmJiOTc2ZjZiLWZkZTAtNDM3Mi04YjIwLTc5ZWJiYzI0MTliZHgxNzg5MDQzNjM4NDkzMzcxMDAw parts=109872026/09/10 12:33:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete988--- PASS: TestGCBugBareHashReferences (2.09s)989=== CONT TestReadProxy4049902026/09/10 12:33:59 INFO Completed upload id=19912026/09/10 12:33:59 INFO Received uploads request method=POST path=/api/pending_closures9922026/09/10 12:33:59 INFO Received uploads request method=POST path=/api/pending_closures9932026/09/10 12:33:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9942026/09/10 12:33:59 WARN Found objects in DB but missing from S3, will re-upload count=1995--- PASS: TestService_verifyS3Integrity (2.69s)996=== CONT TestReadProxyNarStreaming997--- PASS: TestReadRedirectKeepsNarinfoProxied (1.72s)998=== CONT TestReadProxyNarinfoAlreadyDecompressed9992026-09-10 12:33:59.672 UTC [68253] ERROR: relation "goose_db_version" does not exist at character 3610002026-09-10 12:33:59.672 UTC [68253] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1001--- PASS: TestReadRedirectNar (1.44s)1002=== CONT TestReadProxyNarinfo10032026/09/10 12:33:59 OK 20241026095416_initial_model.sql (42.91ms)10042026/09/10 12:33:59 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)10052026/09/10 12:33:59 OK 20251218171726_add_pins.sql (3.53ms)10062026-09-10 12:33:59.760 UTC [68255] ERROR: relation "goose_db_version" does not exist at character 3610072026-09-10 12:33:59.760 UTC [68255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026/09/10 12:33:59 OK 20260628120000_add_object_size_and_stats.sql (6.69ms)10092026/09/10 12:33:59 goose: successfully migrated database to version: 2026062812000010102026/09/10 12:33:59 OK 1_commit_pending_closure.sql (2.54ms)10112026/09/10 12:33:59 OK 2_object_stats_trigger.sql (635.08µs)10122026/09/10 12:33:59 goose: up to current file version: 210132026/09/10 12:33:59 OK 20241026095416_initial_model.sql (57.69ms)10142026/09/10 12:33:59 OK 20251210153512_drop_unused_gin_index.sql (7.8ms)10152026/09/10 12:33:59 OK 20251218171726_add_pins.sql (16.15ms)10162026/09/10 12:33:59 OK 20260628120000_add_object_size_and_stats.sql (17.38ms)10172026/09/10 12:33:59 goose: successfully migrated database to version: 2026062812000010182026/09/10 12:33:59 OK 1_commit_pending_closure.sql (2.48ms)10192026/09/10 12:33:59 OK 2_object_stats_trigger.sql (461.58µs)10202026/09/10 12:33:59 goose: up to current file version: 21021--- PASS: TestReadProxyDisabled (1.37s)1022=== CONT TestService_Rustfstest10232026-09-10 12:33:59.994 UTC [68259] ERROR: relation "goose_db_version" does not exist at character 3610242026-09-10 12:33:59.994 UTC [68259] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10252026-09-10 12:34:00.076 UTC [68262] ERROR: relation "goose_db_version" does not exist at character 3610262026-09-10 12:34:00.076 UTC [68262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1027--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.44s)1028=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10292026/09/10 12:34:00 OK 20241026095416_initial_model.sql (76.94ms)10302026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (7.37ms)10312026/09/10 12:34:00 OK 20251218171726_add_pins.sql (12.09ms)10322026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)10332026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000010342026/09/10 12:34:00 OK 1_commit_pending_closure.sql (1.92ms)10352026/09/10 12:34:00 OK 2_object_stats_trigger.sql (338.38µs)10362026/09/10 12:34:00 goose: up to current file version: 210372026/09/10 12:34:00 OK 20241026095416_initial_model.sql (19.86ms)10382026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (3.64ms)10392026/09/10 12:34:00 OK 20251218171726_add_pins.sql (12.35ms)10402026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (17.48ms)10412026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000010422026/09/10 12:34:00 OK 1_commit_pending_closure.sql (1.78ms)10432026/09/10 12:34:00 OK 2_object_stats_trigger.sql (382.71µs)10442026/09/10 12:34:00 goose: up to current file version: 21045--- PASS: TestReadProxyConditionalGet (1.42s)1046=== CONT TestSkippedUploadsHandler10472026/09/10 12:34:00 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001048--- PASS: TestSkippedUploadsHandler (0.00s)1049=== CONT TestParseSize1050--- PASS: TestParseSize (0.00s)1051=== CONT TestServerTLSConfig1052=== RUN TestServerTLSConfig/no_client_CA1053=== PAUSE TestServerTLSConfig/no_client_CA1054=== RUN TestServerTLSConfig/missing_CA_file1055=== PAUSE TestServerTLSConfig/missing_CA_file1056=== RUN TestServerTLSConfig/not_a_PEM_file1057=== PAUSE TestServerTLSConfig/not_a_PEM_file1058=== CONT TestParseSingleRange1059=== RUN TestParseSingleRange/none1060=== PAUSE TestParseSingleRange/none1061=== RUN TestParseSingleRange/unknown_unit1062=== PAUSE TestParseSingleRange/unknown_unit1063=== RUN TestParseSingleRange/multi-range_ignored1064=== PAUSE TestParseSingleRange/multi-range_ignored1065=== RUN TestParseSingleRange/malformed_no_dash1066=== PAUSE TestParseSingleRange/malformed_no_dash1067=== RUN TestParseSingleRange/malformed_both_empty1068=== PAUSE TestParseSingleRange/malformed_both_empty1069=== RUN TestParseSingleRange/malformed_end_before_start1070=== PAUSE TestParseSingleRange/malformed_end_before_start1071=== RUN TestParseSingleRange/closed1072=== PAUSE TestParseSingleRange/closed1073=== RUN TestParseSingleRange/open-ended1074=== PAUSE TestParseSingleRange/open-ended1075=== RUN TestParseSingleRange/end_clamped_to_size1076=== PAUSE TestParseSingleRange/end_clamped_to_size1077=== RUN TestParseSingleRange/suffix1078=== PAUSE TestParseSingleRange/suffix1079=== RUN TestParseSingleRange/suffix_exceeds_size1080=== PAUSE TestParseSingleRange/suffix_exceeds_size1081=== RUN TestParseSingleRange/single_byte1082=== PAUSE TestParseSingleRange/single_byte1083=== RUN TestParseSingleRange/start_past_EOF1084=== PAUSE TestParseSingleRange/start_past_EOF1085=== RUN TestParseSingleRange/start_far_past_EOF1086=== PAUSE TestParseSingleRange/start_far_past_EOF1087=== CONT TestResurrectedObjectNotDeleted10882026-09-10 12:34:00.402 UTC [68268] ERROR: relation "goose_db_version" does not exist at character 3610892026-09-10 12:34:00.402 UTC [68268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10902026-09-10 12:34:00.494 UTC [68269] ERROR: relation "goose_db_version" does not exist at character 3610912026-09-10 12:34:00.494 UTC [68269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10922026-09-10 12:34:00.509 UTC [68270] ERROR: relation "goose_db_version" does not exist at character 3610932026-09-10 12:34:00.509 UTC [68270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10942026/09/10 12:34:00 OK 20241026095416_initial_model.sql (73.27ms)1095--- PASS: TestReadProxyHead (1.44s)1096=== CONT TestOrphanedObjectsGCStressTest10972026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)10982026/09/10 12:34:00 OK 20251218171726_add_pins.sql (4.98ms)10992026-09-10 12:34:00.522 UTC [68272] ERROR: relation "goose_db_version" does not exist at character 3611002026-09-10 12:34:00.522 UTC [68272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11012026/09/10 12:34:00 OK 20241026095416_initial_model.sql (14.36ms)11022026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (7.94ms)11032026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000011042026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)11052026/09/10 12:34:00 OK 1_commit_pending_closure.sql (3.63ms)11062026/09/10 12:34:00 OK 20251218171726_add_pins.sql (2.98ms)11072026/09/10 12:34:00 OK 2_object_stats_trigger.sql (471.33µs)11082026/09/10 12:34:00 goose: up to current file version: 211092026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (23.86ms)11102026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000011112026/09/10 12:34:00 OK 20241026095416_initial_model.sql (37.62ms)11122026/09/10 12:34:00 OK 1_commit_pending_closure.sql (2.58ms)11132026/09/10 12:34:00 OK 2_object_stats_trigger.sql (325.21µs)11142026/09/10 12:34:00 goose: up to current file version: 211152026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (9.79ms)11162026/09/10 12:34:00 OK 20251218171726_add_pins.sql (30.52ms)11172026/09/10 12:34:00 OK 20241026095416_initial_model.sql (78.14ms)11182026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)11192026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (19.04ms)11202026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000011212026/09/10 12:34:00 OK 20251218171726_add_pins.sql (8.94ms)11222026/09/10 12:34:00 OK 1_commit_pending_closure.sql (2.65ms)11232026/09/10 12:34:00 OK 2_object_stats_trigger.sql (387.75µs)11242026/09/10 12:34:00 goose: up to current file version: 211252026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (24.07ms)11262026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000011272026/09/10 12:34:00 OK 1_commit_pending_closure.sql (2ms)11282026/09/10 12:34:00 OK 2_object_stats_trigger.sql (441µs)11292026/09/10 12:34:00 goose: up to current file version: 211302026-09-10 12:34:00.674 UTC [68274] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-10 12:34:00.674 UTC [68274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1132--- PASS: TestReadProxyInvalidPath (1.31s)1133=== CONT TestOrphanedObjectsGC11342026/09/10 12:34:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01135=== NAME TestPinProtectsFromGC1136 client_integration_test.go:711: Pin successfully protected closure from garbage collection11372026/09/10 12:34:00 OK 20241026095416_initial_model.sql (59.28ms)11382026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (7.38ms)11392026/09/10 12:34:00 OK 20251218171726_add_pins.sql (9.9ms)1140--- PASS: TestPinProtectsFromGC (3.96s)1141=== CONT TestObjectStatsTrigger11422026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (25.99ms)11432026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000011442026/09/10 12:34:00 OK 1_commit_pending_closure.sql (8.35ms)11452026/09/10 12:34:00 OK 2_object_stats_trigger.sql (432.75µs)11462026/09/10 12:34:00 goose: up to current file version: 211472026-09-10 12:34:00.855 UTC [68279] ERROR: relation "goose_db_version" does not exist at character 3611482026-09-10 12:34:00.855 UTC [68279] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1149--- PASS: TestReadProxy404 (1.41s)1150=== CONT TestMultipartCleanup11512026/09/10 12:34:00 OK 20241026095416_initial_model.sql (61.18ms)11522026/09/10 12:34:00 OK 20251210153512_drop_unused_gin_index.sql (5.71ms)11532026/09/10 12:34:00 OK 20251218171726_add_pins.sql (16.64ms)11542026/09/10 12:34:00 OK 20260628120000_add_object_size_and_stats.sql (14.17ms)11552026/09/10 12:34:00 goose: successfully migrated database to version: 2026062812000011562026-09-10 12:34:00.985 UTC [68282] ERROR: relation "goose_db_version" does not exist at character 3611572026-09-10 12:34:00.985 UTC [68282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11582026/09/10 12:34:00 OK 1_commit_pending_closure.sql (2.89ms)11592026/09/10 12:34:00 OK 2_object_stats_trigger.sql (403.96µs)11602026/09/10 12:34:00 goose: up to current file version: 21161--- PASS: TestReadProxyNarStreaming (1.57s)1162=== CONT TestNARDeduplicationMetadataUploadBug11632026/09/10 12:34:01 OK 20241026095416_initial_model.sql (66.78ms)11642026/09/10 12:34:01 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)11652026/09/10 12:34:01 OK 20251218171726_add_pins.sql (14.66ms)11662026/09/10 12:34:01 OK 20260628120000_add_object_size_and_stats.sql (13.93ms)11672026/09/10 12:34:01 goose: successfully migrated database to version: 2026062812000011682026/09/10 12:34:01 OK 1_commit_pending_closure.sql (3.56ms)11692026/09/10 12:34:01 OK 2_object_stats_trigger.sql (379.29µs)11702026/09/10 12:34:01 goose: up to current file version: 21171--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.66s)1172=== CONT TestService_NativeMTLS11732026-09-10 12:34:01.252 UTC [68285] ERROR: relation "goose_db_version" does not exist at character 3611742026-09-10 12:34:01.252 UTC [68285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/09/10 12:34:01 OK 20241026095416_initial_model.sql (70.4ms)11762026/09/10 12:34:01 OK 20251210153512_drop_unused_gin_index.sql (8.38ms)11772026/09/10 12:34:01 OK 20251218171726_add_pins.sql (16.53ms)11782026/09/10 12:34:01 OK 20260628120000_add_object_size_and_stats.sql (31.01ms)11792026/09/10 12:34:01 goose: successfully migrated database to version: 2026062812000011802026/09/10 12:34:01 OK 1_commit_pending_closure.sql (7.62ms)11812026/09/10 12:34:01 OK 2_object_stats_trigger.sql (2.68ms)11822026/09/10 12:34:01 goose: up to current file version: 21183--- PASS: TestReadProxyNarinfo (1.68s)1184=== CONT TestMetricsInventory11852026-09-10 12:34:01.446 UTC [68288] ERROR: relation "goose_db_version" does not exist at character 3611862026-09-10 12:34:01.446 UTC [68288] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11872026/09/10 12:34:01 OK 20241026095416_initial_model.sql (55.03ms)11882026/09/10 12:34:01 OK 20251210153512_drop_unused_gin_index.sql (8.15ms)11892026/09/10 12:34:01 OK 20251218171726_add_pins.sql (26.14ms)11902026-09-10 12:34:01.563 UTC [68291] ERROR: relation "goose_db_version" does not exist at character 3611912026-09-10 12:34:01.563 UTC [68291] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/09/10 12:34:01 OK 20260628120000_add_object_size_and_stats.sql (26.54ms)11932026/09/10 12:34:01 goose: successfully migrated database to version: 2026062812000011942026/09/10 12:34:01 OK 1_commit_pending_closure.sql (4.09ms)11952026/09/10 12:34:01 OK 2_object_stats_trigger.sql (622.46µs)11962026/09/10 12:34:01 goose: up to current file version: 21197--- PASS: TestService_Rustfstest (1.67s)1198=== CONT TestCompletedNarNotReofferedAcrossClosures11992026/09/10 12:34:01 OK 20241026095416_initial_model.sql (69.21ms)12002026/09/10 12:34:01 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)12012026-09-10 12:34:01.691 UTC [68294] ERROR: relation "goose_db_version" does not exist at character 3612022026-09-10 12:34:01.691 UTC [68294] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12032026/09/10 12:34:01 OK 20251218171726_add_pins.sql (36.27ms)12042026/09/10 12:34:01 OK 20260628120000_add_object_size_and_stats.sql (25.39ms)12052026/09/10 12:34:01 goose: successfully migrated database to version: 2026062812000012062026/09/10 12:34:01 OK 1_commit_pending_closure.sql (10.69ms)12072026/09/10 12:34:01 OK 2_object_stats_trigger.sql (632µs)12082026/09/10 12:34:01 goose: up to current file version: 212092026-09-10 12:34:01.749 UTC [68296] ERROR: relation "goose_db_version" does not exist at character 3612102026-09-10 12:34:01.749 UTC [68296] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12112026/09/10 12:34:01 INFO Received uploads request method=POST path=/api/pending_closures12122026/09/10 12:34:01 OK 20241026095416_initial_model.sql (102.84ms)12132026/09/10 12:34:01 OK 20251210153512_drop_unused_gin_index.sql (4.32ms)12142026/09/10 12:34:01 OK 20241026095416_initial_model.sql (77.89ms)12152026/09/10 12:34:01 OK 20251218171726_add_pins.sql (17.36ms)12162026/09/10 12:34:01 OK 20251210153512_drop_unused_gin_index.sql (6.85ms)12172026/09/10 12:34:01 OK 20260628120000_add_object_size_and_stats.sql (30.57ms)12182026/09/10 12:34:01 goose: successfully migrated database to version: 2026062812000012192026/09/10 12:34:01 OK 20251218171726_add_pins.sql (29.76ms)12202026/09/10 12:34:01 OK 1_commit_pending_closure.sql (7.85ms)12212026/09/10 12:34:01 OK 2_object_stats_trigger.sql (605.92µs)12222026/09/10 12:34:01 goose: up to current file version: 212232026/09/10 12:34:01 OK 20260628120000_add_object_size_and_stats.sql (27.61ms)12242026/09/10 12:34:01 goose: successfully migrated database to version: 2026062812000012252026-09-10 12:34:01.944 UTC [68297] ERROR: relation "goose_db_version" does not exist at character 3612262026-09-10 12:34:01.944 UTC [68297] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12272026/09/10 12:34:01 OK 1_commit_pending_closure.sql (17.51ms)12282026/09/10 12:34:01 OK 2_object_stats_trigger.sql (729.63µs)12292026/09/10 12:34:01 goose: up to current file version: 212302026/09/10 12:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1231--- PASS: TestResurrectedObjectNotDeleted (1.76s)1232=== CONT TestPresignedUploadRegisteredBeforeCommit12332026/09/10 12:34:02 OK 20241026095416_initial_model.sql (105.79ms)12342026/09/10 12:34:02 OK 20251210153512_drop_unused_gin_index.sql (8.34ms)12352026/09/10 12:34:02 OK 20251218171726_add_pins.sql (13.85ms)12362026/09/10 12:34:02 OK 20260628120000_add_object_size_and_stats.sql (16.69ms)12372026/09/10 12:34:02 goose: successfully migrated database to version: 2026062812000012382026/09/10 12:34:02 OK 1_commit_pending_closure.sql (2.33ms)12392026/09/10 12:34:02 OK 2_object_stats_trigger.sql (422.33µs)12402026/09/10 12:34:02 goose: up to current file version: 212412026-09-10 12:34:02.185 UTC [68300] ERROR: relation "goose_db_version" does not exist at character 3612422026-09-10 12:34:02.185 UTC [68300] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026/09/10 12:34:02 OK 20241026095416_initial_model.sql (54.42ms)12442026/09/10 12:34:02 OK 20251210153512_drop_unused_gin_index.sql (13.79ms)12452026/09/10 12:34:02 OK 20251218171726_add_pins.sql (16.27ms)12462026/09/10 12:34:02 OK 20260628120000_add_object_size_and_stats.sql (20.34ms)12472026/09/10 12:34:02 goose: successfully migrated database to version: 2026062812000012482026/09/10 12:34:02 OK 1_commit_pending_closure.sql (8.74ms)12492026/09/10 12:34:02 OK 2_object_stats_trigger.sql (803.92µs)12502026/09/10 12:34:02 goose: up to current file version: 212512026-09-10 12:34:02.340 UTC [68301] ERROR: relation "goose_db_version" does not exist at character 3612522026-09-10 12:34:02.340 UTC [68301] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/09/10 12:34:02 OK 20241026095416_initial_model.sql (65.24ms)12542026/09/10 12:34:02 OK 20251210153512_drop_unused_gin_index.sql (8.44ms)12552026/09/10 12:34:02 OK 20251218171726_add_pins.sql (11.18ms)12562026/09/10 12:34:02 OK 20260628120000_add_object_size_and_stats.sql (16.89ms)12572026/09/10 12:34:02 goose: successfully migrated database to version: 2026062812000012582026/09/10 12:34:02 OK 1_commit_pending_closure.sql (4.7ms)12592026/09/10 12:34:02 OK 2_object_stats_trigger.sql (1.13ms)12602026/09/10 12:34:02 goose: up to current file version: 21261--- PASS: TestObjectStatsTrigger (1.77s)1262=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12632026-09-10 12:34:02.578 UTC [68302] ERROR: relation "goose_db_version" does not exist at character 3612642026-09-10 12:34:02.578 UTC [68302] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12652026/09/10 12:34:02 INFO Received uploads request method=POST path=/api/pending_closures12662026/09/10 12:34:02 OK 20241026095416_initial_model.sql (178.89ms)12672026/09/10 12:34:02 OK 20251210153512_drop_unused_gin_index.sql (8.5ms)12682026/09/10 12:34:02 OK 20251218171726_add_pins.sql (42.71ms)12692026/09/10 12:34:02 OK 20260628120000_add_object_size_and_stats.sql (38.62ms)12702026/09/10 12:34:02 goose: successfully migrated database to version: 2026062812000012712026/09/10 12:34:02 OK 1_commit_pending_closure.sql (6.52ms)12722026/09/10 12:34:02 OK 2_object_stats_trigger.sql (1.97ms)12732026/09/10 12:34:02 goose: up to current file version: 212742026/09/10 12:34:02 INFO Received cleanup request method=DELETE path=/api/pending_closures12752026/09/10 12:34:02 INFO Aborted multipart uploads count=11276=== NAME TestOrphanedObjectsGC1277 orphaned_objects_gc_test.go:290: GC Test Summary:1278 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1279 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1280 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1281 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1282 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1283--- PASS: TestOrphanedObjectsGC (2.23s)1284=== CONT TestCacheConfigHandlerMaxNarSize1285--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1286=== CONT TestCreatePendingClosureRejectsOversizedNAR12872026/09/10 12:34:02 INFO Received uploads request method=POST path=/api/pending_closures1288--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1289=== CONT TestRedundantMultipartUpload1290--- PASS: TestMultipartCleanup (2.07s)1291=== CONT TestGenerateLandingPage1292--- PASS: TestGenerateLandingPage (0.00s)1293=== CONT TestCacheConfigHandler1294=== RUN TestCacheConfigHandler/full_config,_no_issuer1295=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1296=== RUN TestCacheConfigHandler/no_cache_url_configured1297=== PAUSE TestCacheConfigHandler/no_cache_url_configured1298=== RUN TestCacheConfigHandler/no_signing_keys1299=== PAUSE TestCacheConfigHandler/no_signing_keys1300=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1301=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1302=== CONT TestClientWithDependencies1303=== NAME TestNARDeduplicationMetadataUploadBug1304 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-68052-3578224089/TestNARDeduplicationMetadataUploadBug2888513539/001/store/6w5jbfgzsfnxmivxbcqnwqrq3a2ypzcd-file1.txt13052026/09/10 12:34:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13062026/09/10 12:34:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1307--- PASS: TestService_NativeMTLS (2.03s)1308=== CONT TestClientMultipleUploads13092026-09-10 12:34:03.281 UTC [68312] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-10 12:34:03.281 UTC [68312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13112026/09/10 12:34:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13122026/09/10 12:34:03 INFO Received uploads request method=POST path=/api/pending_closures13132026/09/10 12:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13142026/09/10 12:34:03 INFO Uploading 6w5jbfgzsfnxmivxbcqnwqrq3a2ypzcd-file1.txt (160B)13152026/09/10 12:34:03 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13162026/09/10 12:34:03 WARN Failed to register uploaded object key=6w5jbfgzsfnxmivxbcqnwqrq3a2ypzcd.ls error="server returned 404: 404 page not found\n"13172026/09/10 12:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13182026/09/10 12:34:03 INFO Signed narinfos id=1 count=113192026/09/10 12:34:03 INFO Uploading 1 narinfos13202026/09/10 12:34:03 OK 20241026095416_initial_model.sql (128.93ms)13212026/09/10 12:34:03 WARN Failed to register uploaded object key=6w5jbfgzsfnxmivxbcqnwqrq3a2ypzcd.narinfo error="server returned 404: 404 page not found\n"13222026/09/10 12:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13232026/09/10 12:34:03 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)13242026/09/10 12:34:03 INFO Completed upload id=113252026/09/10 12:34:03 INFO Upload complete. (195ms)1326=== NAME TestNARDeduplicationMetadataUploadBug1327 metadata_upload_test.go:54: Retrieved narinfo from S3:1328 StorePath: /nix/var/nix/builds/nix-68052-3578224089/TestNARDeduplicationMetadataUploadBug2888513539/001/store/6w5jbfgzsfnxmivxbcqnwqrq3a2ypzcd-file1.txt1329 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1330 Compression: zstd1331 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1332 NarSize: 1601333 References: 1334 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1335 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1336 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1337 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13382026/09/10 12:34:03 OK 20251218171726_add_pins.sql (25.6ms)13392026/09/10 12:34:03 OK 20260628120000_add_object_size_and_stats.sql (24.92ms)13402026/09/10 12:34:03 goose: successfully migrated database to version: 2026062812000013412026/09/10 12:34:03 OK 1_commit_pending_closure.sql (9.17ms)13422026/09/10 12:34:03 OK 2_object_stats_trigger.sql (225.71µs)13432026/09/10 12:34:03 goose: up to current file version: 21344--- PASS: TestMetricsInventory (2.10s)1345=== CONT TestClientIntegration1346=== NAME TestNARDeduplicationMetadataUploadBug1347 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-68052-3578224089/TestNARDeduplicationMetadataUploadBug2888513539/001/store/nryd3l3y96j5ipf3a0lzc4k6ivbwvxb6-file2.txt13482026/09/10 12:34:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13492026/09/10 12:34:03 INFO Received uploads request method=POST path=/api/pending_closures13502026/09/10 12:34:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13512026/09/10 12:34:03 WARN Failed to register uploaded object key=nryd3l3y96j5ipf3a0lzc4k6ivbwvxb6.ls error="server returned 404: 404 page not found\n"13522026/09/10 12:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13532026/09/10 12:34:03 INFO Signed narinfos id=2 count=113542026/09/10 12:34:03 INFO Uploading 1 narinfos13552026/09/10 12:34:03 INFO Received uploads request method=POST path=/api/pending_closures13562026/09/10 12:34:03 WARN Failed to register uploaded object key=nryd3l3y96j5ipf3a0lzc4k6ivbwvxb6.narinfo error="server returned 404: 404 page not found\n"13572026/09/10 12:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13582026/09/10 12:34:03 INFO Completed upload id=213592026/09/10 12:34:03 INFO Upload complete. (116ms)1360 metadata_upload_test.go:76: Retrieved narinfo from S3:1361 StorePath: /nix/var/nix/builds/nix-68052-3578224089/TestNARDeduplicationMetadataUploadBug2888513539/001/store/nryd3l3y96j5ipf3a0lzc4k6ivbwvxb6-file2.txt1362 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1363 Compression: zstd1364 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1365 NarSize: 1601366 References: 1367 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1368 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1369 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1370 {"version":1,"root":{"type":"regular","size":44}}1371--- PASS: TestNARDeduplicationMetadataUploadBug (2.68s)1372=== CONT TestClientErrorHandling1373=== RUN TestClientErrorHandling/InvalidStorePath1374=== PAUSE TestClientErrorHandling/InvalidStorePath1375=== RUN TestClientErrorHandling/InvalidAuthToken1376=== PAUSE TestClientErrorHandling/InvalidAuthToken1377=== RUN TestClientErrorHandling/ServerNotAvailable1378=== PAUSE TestClientErrorHandling/ServerNotAvailable1379=== CONT TestClientCADerivations13802026-09-10 12:34:03.784 UTC [68332] ERROR: relation "goose_db_version" does not exist at character 3613812026-09-10 12:34:03.784 UTC [68332] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13822026/09/10 12:34:03 INFO Received uploads request method=POST path=/api/pending_closures13832026/09/10 12:34:03 OK 20241026095416_initial_model.sql (108.74ms)13842026/09/10 12:34:03 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)13852026/09/10 12:34:03 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13862026/09/10 12:34:03 INFO Received uploads request method=POST path=/api/pending_closures1387--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.84s)1388=== CONT TestCacheStatsHandler13892026/09/10 12:34:03 OK 20251218171726_add_pins.sql (2.66ms)13902026/09/10 12:34:03 OK 20260628120000_add_object_size_and_stats.sql (14.18ms)13912026/09/10 12:34:03 goose: successfully migrated database to version: 2026062812000013922026/09/10 12:34:03 OK 1_commit_pending_closure.sql (5.46ms)13932026/09/10 12:34:03 OK 2_object_stats_trigger.sql (444.46µs)13942026/09/10 12:34:03 goose: up to current file version: 213952026-09-10 12:34:04.027 UTC [68335] ERROR: relation "goose_db_version" does not exist at character 3613962026-09-10 12:34:04.027 UTC [68335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13972026/09/10 12:34:04 INFO Received uploads request method=POST path=/api/pending_closures13982026/09/10 12:34:04 OK 20241026095416_initial_model.sql (165.43ms)13992026/09/10 12:34:04 OK 20251210153512_drop_unused_gin_index.sql (13.71ms)14002026/09/10 12:34:04 OK 20251218171726_add_pins.sql (36.12ms)14012026/09/10 12:34:04 OK 20260628120000_add_object_size_and_stats.sql (29.5ms)14022026/09/10 12:34:04 goose: successfully migrated database to version: 2026062812000014032026/09/10 12:34:04 OK 1_commit_pending_closure.sql (6.99ms)14042026/09/10 12:34:04 OK 2_object_stats_trigger.sql (573.04µs)14052026/09/10 12:34:04 goose: up to current file version: 214062026-09-10 12:34:04.467 UTC [68336] ERROR: relation "goose_db_version" does not exist at character 3614072026-09-10 12:34:04.467 UTC [68336] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14082026/09/10 12:34:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14092026/09/10 12:34:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDA1ZjE5YmUtNmUwZC00YTNiLWFiNmItOGQ3ZjU1ZDkwZmVmLmUwNzUxYWU1LTViY2QtNDUwYi05Y2U0LThmYWRhZWI0NTI4MngxNzg5MDQzNjQ0MjM1NjAwMDAw14102026/09/10 12:34:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDA1ZjE5YmUtNmUwZC00YTNiLWFiNmItOGQ3ZjU1ZDkwZmVmLmUwNzUxYWU1LTViY2QtNDUwYi05Y2U0LThmYWRhZWI0NTI4MngxNzg5MDQzNjQ0MjM1NjAwMDAw parts=11411--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.96s)1412=== CONT TestService_AuthMiddleware_OIDC14132026/09/10 12:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65411/oidc14142026/09/10 12:34:04 OK 20241026095416_initial_model.sql (190.67ms)14152026/09/10 12:34:04 OK 20251210153512_drop_unused_gin_index.sql (12.29ms)14162026/09/10 12:34:04 OK 20251218171726_add_pins.sql (15.9ms)14172026/09/10 12:34:04 OK 20260628120000_add_object_size_and_stats.sql (23.57ms)14182026/09/10 12:34:04 goose: successfully migrated database to version: 2026062812000014192026/09/10 12:34:04 OK 1_commit_pending_closure.sql (8.16ms)14202026/09/10 12:34:04 OK 2_object_stats_trigger.sql (275.46µs)14212026/09/10 12:34:04 goose: up to current file version: 214222026-09-10 12:34:04.859 UTC [68340] ERROR: relation "goose_db_version" does not exist at character 3614232026-09-10 12:34:04.859 UTC [68340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14242026/09/10 12:34:05 INFO Received uploads request method=POST path=/api/pending_closures14252026/09/10 12:34:05 OK 20241026095416_initial_model.sql (187.49ms)14262026/09/10 12:34:05 OK 20251210153512_drop_unused_gin_index.sql (6.07ms)14272026/09/10 12:34:05 OK 20251218171726_add_pins.sql (24.6ms)14282026/09/10 12:34:05 INFO Received uploads request method=POST path=/api/pending_closures14292026/09/10 12:34:05 OK 20260628120000_add_object_size_and_stats.sql (34.08ms)14302026/09/10 12:34:05 goose: successfully migrated database to version: 2026062812000014312026/09/10 12:34:05 OK 1_commit_pending_closure.sql (14.32ms)1432=== NAME TestClientWithDependencies1433 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-68052-3578224089/TestClientWithDependencies1841667647/001/store/rw8xrkrsaip4z0fslmgv80059bam8532-test-script14342026/09/10 12:34:05 OK 2_object_stats_trigger.sql (241.08µs)14352026/09/10 12:34:05 goose: up to current file version: 21436 client_integration_test.go:596: Found 1 dependencies (including self)14372026/09/10 12:34:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14382026/09/10 12:34:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14392026/09/10 12:34:05 INFO Received uploads request method=POST path=/api/pending_closures14402026/09/10 12:34:05 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDA1ZjE5YmUtNmUwZC00YTNiLWFiNmItOGQ3ZjU1ZDkwZmVmLmQxMGQ3ZGVkLWUxY2QtNDYyMC1hYjljLTdmYTYxM2FjMjU1ZHgxNzg5MDQzNjQzNjk4OTg4MDAw parts=1214412026/09/10 12:34:05 INFO Received uploads request method=POST path=/api/pending_closures1442--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.74s)1443=== CONT TestService_ReadScope_PublicByDefault14442026/09/10 12:34:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14452026/09/10 12:34:05 INFO Uploading rw8xrkrsaip4z0fslmgv80059bam8532-test-script (136B)14462026/09/10 12:34:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14472026/09/10 12:34:05 WARN Failed to register uploaded object key=log/dick980s9c2pm7nxahznahl443iy8s2d-test-script.drv error="server returned 404: 404 page not found\n"14482026/09/10 12:34:05 WARN Failed to register uploaded object key=rw8xrkrsaip4z0fslmgv80059bam8532.ls error="server returned 404: 404 page not found\n"14492026/09/10 12:34:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14502026/09/10 12:34:05 INFO Signed narinfos id=1 count=114512026/09/10 12:34:05 INFO Uploading 1 narinfos14522026/09/10 12:34:05 WARN Failed to register uploaded object key=rw8xrkrsaip4z0fslmgv80059bam8532.narinfo error="server returned 404: 404 page not found\n"14532026/09/10 12:34:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14542026-09-10 12:34:05.436 UTC [68353] ERROR: relation "goose_db_version" does not exist at character 3614552026-09-10 12:34:05.436 UTC [68353] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14562026/09/10 12:34:05 INFO Completed upload id=114572026/09/10 12:34:05 INFO Upload complete. (170ms)1458=== NAME TestClientWithDependencies1459 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-68052-3578224089/TestClientWithDependencies1841667647/001/store) requires matching store prefix1460--- PASS: TestClientWithDependencies (2.58s)1461=== CONT TestService_RequireScope_OIDC14622026/09/10 12:34:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65421/oidc14632026/09/10 12:34:05 OK 20241026095416_initial_model.sql (139.39ms)14642026/09/10 12:34:05 OK 20251210153512_drop_unused_gin_index.sql (7.79ms)14652026-09-10 12:34:05.653 UTC [68358] ERROR: relation "goose_db_version" does not exist at character 3614662026-09-10 12:34:05.653 UTC [68358] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14672026/09/10 12:34:05 OK 20251218171726_add_pins.sql (30.89ms)1468=== NAME TestClientMultipleUploads1469 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-68052-3578224089/TestClientMultipleUploads1825465371/001/store/55ri48vb596w2z8d7b1rf4mqiqysybl7-test-file-0.txt14702026/09/10 12:34:05 OK 20260628120000_add_object_size_and_stats.sql (31.45ms)14712026/09/10 12:34:05 goose: successfully migrated database to version: 2026062812000014722026/09/10 12:34:05 OK 1_commit_pending_closure.sql (4.91ms)14732026/09/10 12:34:05 OK 2_object_stats_trigger.sql (289.04µs)14742026/09/10 12:34:05 goose: up to current file version: 21475 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-68052-3578224089/TestClientMultipleUploads1825465371/001/store/wp3xc5ri61imcbfprwll23p9nhlipcz1-test-file-1.txt14762026-09-10 12:34:05.846 UTC [68361] ERROR: relation "goose_db_version" does not exist at character 3614772026-09-10 12:34:05.846 UTC [68361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14782026/09/10 12:34:05 OK 20241026095416_initial_model.sql (172.47ms)1479 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-68052-3578224089/TestClientMultipleUploads1825465371/001/store/2x9amdvdydv6mrc5ffgsvggvz3vfaw8i-test-file-2.txt14802026/09/10 12:34:05 OK 20251210153512_drop_unused_gin_index.sql (12.17ms)14812026/09/10 12:34:05 OK 20251218171726_add_pins.sql (5.58ms)14822026/09/10 12:34:05 OK 20260628120000_add_object_size_and_stats.sql (30.64ms)14832026/09/10 12:34:05 goose: successfully migrated database to version: 2026062812000014842026/09/10 12:34:05 OK 1_commit_pending_closure.sql (10.69ms)14852026/09/10 12:34:05 OK 2_object_stats_trigger.sql (232.29µs)14862026/09/10 12:34:05 goose: up to current file version: 214872026/09/10 12:34:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14882026/09/10 12:34:05 WARN Rate limiter enabled after throttle name=s3-test rate=514892026/09/10 12:34:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1490=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1491 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101492 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001493--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.89s)1494=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14952026/09/10 12:34:06 INFO Received uploads request method=POST path=/api/pending_closures14962026/09/10 12:34:06 INFO Received uploads request method=POST path=/api/pending_closures14972026/09/10 12:34:06 INFO Received uploads request method=POST path=/api/pending_closures14982026/09/10 12:34:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14992026/09/10 12:34:06 INFO Uploading 2x9amdvdydv6mrc5ffgsvggvz3vfaw8i-test-file-2.txt (160B)15002026/09/10 12:34:06 INFO Uploading 55ri48vb596w2z8d7b1rf4mqiqysybl7-test-file-0.txt (160B)15012026/09/10 12:34:06 INFO Uploading wp3xc5ri61imcbfprwll23p9nhlipcz1-test-file-1.txt (160B)15022026/09/10 12:34:06 OK 20241026095416_initial_model.sql (194.16ms)15032026/09/10 12:34:06 OK 20251210153512_drop_unused_gin_index.sql (10.28ms)15042026/09/10 12:34:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15052026/09/10 12:34:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15062026/09/10 12:34:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15072026/09/10 12:34:06 WARN Failed to register uploaded object key=55ri48vb596w2z8d7b1rf4mqiqysybl7.ls error="server returned 404: 404 page not found\n"15082026/09/10 12:34:06 OK 20251218171726_add_pins.sql (33.21ms)15092026/09/10 12:34:06 WARN Failed to register uploaded object key=2x9amdvdydv6mrc5ffgsvggvz3vfaw8i.ls error="server returned 404: 404 page not found\n"15102026/09/10 12:34:06 WARN Failed to register uploaded object key=wp3xc5ri61imcbfprwll23p9nhlipcz1.ls error="server returned 404: 404 page not found\n"15112026/09/10 12:34:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15122026/09/10 12:34:06 INFO Signed narinfos id=1 count=115132026/09/10 12:34:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15142026/09/10 12:34:06 INFO Signed narinfos id=2 count=115152026/09/10 12:34:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15162026/09/10 12:34:06 INFO Signed narinfos id=3 count=115172026/09/10 12:34:06 INFO Uploading 3 narinfos15182026/09/10 12:34:06 WARN Failed to register uploaded object key=wp3xc5ri61imcbfprwll23p9nhlipcz1.narinfo error="server returned 404: 404 page not found\n"15192026/09/10 12:34:06 WARN Failed to register uploaded object key=55ri48vb596w2z8d7b1rf4mqiqysybl7.narinfo error="server returned 404: 404 page not found\n"15202026/09/10 12:34:06 WARN Failed to register uploaded object key=2x9amdvdydv6mrc5ffgsvggvz3vfaw8i.narinfo error="server returned 404: 404 page not found\n"15212026/09/10 12:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15222026/09/10 12:34:06 OK 20260628120000_add_object_size_and_stats.sql (28.84ms)15232026/09/10 12:34:06 goose: successfully migrated database to version: 2026062812000015242026/09/10 12:34:06 OK 1_commit_pending_closure.sql (8.11ms)15252026/09/10 12:34:06 OK 2_object_stats_trigger.sql (227.21µs)15262026/09/10 12:34:06 goose: up to current file version: 215272026/09/10 12:34:06 INFO Completed upload id=115282026/09/10 12:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15292026/09/10 12:34:06 INFO Completed upload id=215302026/09/10 12:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15312026/09/10 12:34:06 INFO Completed upload id=315322026/09/10 12:34:06 INFO Upload complete. (269ms)1533=== NAME TestClientMultipleUploads1534 client_integration_test.go:350: Uploaded 3 paths in 300.319791ms1535=== NAME TestClientIntegration1536 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-68052-3578224089/TestClientIntegration1450748250/002/store/l5ddykig5i18yw4da9zp23v8j9607313-test-file.txt1537--- PASS: TestClientMultipleUploads (3.02s)1538=== CONT TestService_ReadAuthMiddleware15392026/09/10 12:34:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15402026/09/10 12:34:06 INFO Received uploads request method=POST path=/api/pending_closures15412026/09/10 12:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15422026/09/10 12:34:06 INFO Uploading l5ddykig5i18yw4da9zp23v8j9607313-test-file.txt (152B)15432026/09/10 12:34:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15442026/09/10 12:34:06 WARN Failed to register uploaded object key=l5ddykig5i18yw4da9zp23v8j9607313.ls error="server returned 404: 404 page not found\n"15452026/09/10 12:34:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15462026/09/10 12:34:06 INFO Signed narinfos id=1 count=115472026/09/10 12:34:06 INFO Uploading 1 narinfos15482026/09/10 12:34:06 WARN Failed to register uploaded object key=l5ddykig5i18yw4da9zp23v8j9607313.narinfo error="server returned 404: 404 page not found\n"15492026/09/10 12:34:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15502026/09/10 12:34:06 INFO Completed upload id=115512026/09/10 12:34:06 INFO Upload complete. (222ms)1552=== NAME TestClientIntegration1553 client_integration_test.go:293: Retrieved narinfo from S3:1554 StorePath: /nix/var/nix/builds/nix-68052-3578224089/TestClientIntegration1450748250/002/store/l5ddykig5i18yw4da9zp23v8j9607313-test-file.txt1555 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1556 Compression: zstd1557 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11558 NarSize: 1521559 References: 1560 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11561 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1562 client_integration_test.go:294: Decompressed .ls content (64 bytes):1563 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1564 client_integration_test.go:297: Testing garbage collection...15652026/09/10 12:34:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures15662026/09/10 12:34:06 INFO Garbage collection started15672026/09/10 12:34:06 INFO Aborted multipart uploads count=015682026/09/10 12:34:06 WARN Force mode enabled - objects will be deleted immediately without grace period15692026-09-10 12:34:06.584 UTC [68384] ERROR: relation "goose_db_version" does not exist at character 3615702026-09-10 12:34:06.584 UTC [68384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1571=== NAME TestOrphanedObjectsGCStressTest1572 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1573--- PASS: TestCacheStatsHandler (2.71s)1574=== CONT TestService_AuthMiddleware_MTLSProxyHeader15752026/09/10 12:34:06 OK 20241026095416_initial_model.sql (16.42ms)15762026/09/10 12:34:06 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)15772026/09/10 12:34:06 OK 20251218171726_add_pins.sql (2.28ms)1578=== NAME TestOrphanedObjectsGCStressTest1579 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion15802026/09/10 12:34:06 OK 20260628120000_add_object_size_and_stats.sql (23.04ms)15812026/09/10 12:34:06 goose: successfully migrated database to version: 2026062812000015822026/09/10 12:34:06 OK 1_commit_pending_closure.sql (1.85ms)15832026/09/10 12:34:06 OK 2_object_stats_trigger.sql (235.38µs)15842026/09/10 12:34:06 goose: up to current file version: 215852026/09/10 12:34:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15862026/09/10 12:34:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDA1ZjE5YmUtNmUwZC00YTNiLWFiNmItOGQ3ZjU1ZDkwZmVmLmM1OTA5YmUxLWY3ZTctNGM3ZS1hODk2LTBjNzc4ZTA3ZmY5N3gxNzg5MDQzNjQ1MTI1NTMwMDAw parts=121587--- PASS: TestRedundantMultipartUpload (3.84s)1588=== CONT TestProxyWriteTimeout/narinfo1589=== CONT TestProxyWriteTimeout/unknown_size1590=== CONT TestProxyWriteTimeout/10_GiB_nar1591=== CONT TestProxyWriteTimeout/1_GiB_nar1592--- PASS: TestProxyWriteTimeout (0.00s)1593 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1594 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1595 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1596 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1597=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15982026/09/10 12:34:06 INFO Received uploads request method=POST path=/1599=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16002026/09/10 12:34:06 INFO Received request for more parts method=POST path=/1601=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16022026/09/10 12:34:06 INFO Received complete multipart upload request method=POST path=/1603=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16042026/09/10 12:34:06 INFO Received uploads request method=POST path=/1605--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1606 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1607 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1608 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1609 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1610=== CONT TestIsValidUploadKey/narinfo1611=== CONT TestIsValidUploadKey/realisation_plus_in_output1612=== CONT TestIsValidUploadKey/unknown_type1613=== CONT TestIsValidUploadKey/empty_key1614=== CONT TestIsValidUploadKey/absolute1615=== CONT TestIsValidUploadKey/traversal_nar1616=== CONT TestIsValidUploadKey/traversal1617=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1618=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1619=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1620=== CONT TestIsValidUploadKey/index.html1621=== CONT TestIsValidUploadKey/nix-cache-info1622=== CONT TestIsValidUploadKey/build_log_home-manager_file1623=== CONT TestIsValidUploadKey/realisation1624=== CONT TestIsValidUploadKey/build_log_equals1625=== CONT TestIsValidUploadKey/build_log_question_mark1626=== CONT TestIsValidUploadKey/build_log_plus_in_name1627=== CONT TestIsValidUploadKey/nar_plain1628=== CONT TestIsValidUploadKey/build_log1629=== CONT TestIsValidUploadKey/listing1630=== CONT TestIsValidUploadKey/nar_xz1631=== CONT TestIsValidUploadKey/nar_zst1632--- PASS: TestIsValidUploadKey (0.04s)1633 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1634 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1635 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1636 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1637 --- PASS: TestIsValidUploadKey/absolute (0.00s)1638 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1639 --- PASS: TestIsValidUploadKey/traversal (0.00s)1640 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1641 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1642 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1643 --- PASS: TestIsValidUploadKey/index.html (0.00s)1644 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1645 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1646 --- PASS: TestIsValidUploadKey/realisation (0.00s)1647 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1648 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1649 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1650 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1651 --- PASS: TestIsValidUploadKey/build_log (0.00s)1652 --- PASS: TestIsValidUploadKey/listing (0.00s)1653 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1654 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1655=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16562026/09/10 12:34:06 INFO Received uploads request method=POST path=/1657=== NAME TestClientCADerivations1658 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-68052-3578224089/TestClientCADerivations2675078241/001/store/4d7m92mva2nsiy4phg3hqyhxrqwq8hyr-ca-test16592026/09/10 12:34:06 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=016602026/09/10 12:34:06 INFO Vacuumed table table=pending_closures16612026/09/10 12:34:06 INFO Vacuumed table table=pending_objects16622026/09/10 12:34:06 INFO Vacuumed table table=multipart_uploads1663 client_ca_test.go:139: Found 1 dependencies (including self)16642026/09/10 12:34:06 INFO Vacuumed table table=closures16652026-09-10 12:34:06.874 UTC [68397] ERROR: relation "goose_db_version" does not exist at character 3616662026-09-10 12:34:06.874 UTC [68397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16672026/09/10 12:34:06 INFO Vacuumed table table=objects1668=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1669=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1670=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1671=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1672=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1673=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1674=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1675=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1676=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16772026/09/10 12:34:06 INFO Received request for more parts method=POST path=/16782026-09-10 12:34:06.906 UTC [68400] ERROR: relation "goose_db_version" does not exist at character 3616792026-09-10 12:34:06.906 UTC [68400] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16802026/09/10 12:34:06 OK 20241026095416_initial_model.sql (13.47ms)16812026/09/10 12:34:06 OK 20251210153512_drop_unused_gin_index.sql (471.04µs)16822026/09/10 12:34:06 OK 20251218171726_add_pins.sql (1.73ms)1683=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16842026/09/10 12:34:06 INFO Received complete multipart upload request method=POST path=/16852026/09/10 12:34:06 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)16862026/09/10 12:34:06 goose: successfully migrated database to version: 2026062812000016872026/09/10 12:34:06 OK 20241026095416_initial_model.sql (7.46ms)16882026/09/10 12:34:06 OK 1_commit_pending_closure.sql (1.47ms)16892026/09/10 12:34:06 OK 20251210153512_drop_unused_gin_index.sql (508.17µs)16902026/09/10 12:34:06 OK 2_object_stats_trigger.sql (694.17µs)16912026/09/10 12:34:06 goose: up to current file version: 216922026/09/10 12:34:06 OK 20251218171726_add_pins.sql (1.04ms)1693=== CONT TestResolveDBConnectionString/flag_wins1694=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1695=== CONT TestResolveDBConnectionString/nothing_configured1696=== CONT TestResolveDBConnectionString/missing_file_is_an_error1697=== CONT TestResolveDBConnectionString/file_when_flag_empty1698=== CONT TestIsValidCachePath/narinfo1699=== CONT TestIsValidCachePath/index.html1700=== CONT TestIsValidCachePath/short_hash1701=== CONT TestIsValidCachePath/wrong_extension1702=== CONT TestIsValidCachePath/leading_slash1703=== CONT TestIsValidCachePath/empty1704=== CONT TestIsValidCachePath/random_path1705=== CONT TestIsValidCachePath/invalid_char_u1706=== CONT TestIsValidCachePath/invalid_char_e1707=== CONT TestIsValidCachePath/traversal_in_middle1708=== CONT TestIsValidCachePath/traversal_parent1709=== CONT TestIsValidCachePath/nar_uncompressed1710=== CONT TestIsValidCachePath/nix-cache-info1711=== CONT TestIsValidCachePath/realisation1712=== CONT TestIsValidCachePath/log1713=== CONT TestIsValidCachePath/ls1714=== CONT TestIsValidCachePath/nar_xz1715=== CONT TestIsValidCachePath/nar_bz21716=== CONT TestIsValidCachePath/nar_zst1717=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1718--- 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)1739=== CONT TestServerTLSConfig/no_client_CA1740=== CONT TestServerTLSConfig/not_a_PEM_file1741--- PASS: TestResolveDBConnectionString (0.01s)1742 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1743 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1744 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1745 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1746 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1747=== CONT TestServerTLSConfig/missing_CA_file1748--- PASS: TestServerTLSConfig (0.00s)1749 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1750 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1751 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1752=== CONT TestParseSingleRange/none1753=== CONT TestParseSingleRange/open-ended1754=== CONT TestParseSingleRange/start_far_past_EOF1755=== CONT TestParseSingleRange/start_past_EOF1756=== CONT TestParseSingleRange/single_byte1757=== CONT TestParseSingleRange/suffix_exceeds_size1758=== CONT TestParseSingleRange/suffix1759=== CONT TestParseSingleRange/end_clamped_to_size1760=== CONT TestParseSingleRange/malformed_both_empty1761=== CONT TestParseSingleRange/closed1762=== CONT TestParseSingleRange/malformed_end_before_start1763=== CONT TestParseSingleRange/multi-range_ignored1764=== CONT TestParseSingleRange/malformed_no_dash1765=== CONT TestParseSingleRange/unknown_unit1766--- PASS: TestParseSingleRange (0.00s)1767 --- PASS: TestParseSingleRange/none (0.00s)1768 --- PASS: TestParseSingleRange/open-ended (0.00s)1769 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1770 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1771 --- PASS: TestParseSingleRange/single_byte (0.00s)1772 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1773 --- PASS: TestParseSingleRange/suffix (0.00s)1774 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1775 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1776 --- PASS: TestParseSingleRange/closed (0.00s)1777 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1778 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1779 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1780 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1781=== CONT TestCacheConfigHandler/full_config,_no_issuer1782=== CONT TestCacheConfigHandler/no_signing_keys1783=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1784=== CONT TestCacheConfigHandler/no_cache_url_configured1785--- PASS: TestCacheConfigHandler (0.00s)1786 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1787 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1788 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1789 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1790=== CONT TestClientErrorHandling/InvalidStorePath17912026/09/10 12:34:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17922026/09/10 12:34:06 OK 20260628120000_add_object_size_and_stats.sql (28.17ms)17932026/09/10 12:34:06 goose: successfully migrated database to version: 2026062812000017942026/09/10 12:34:06 OK 1_commit_pending_closure.sql (1.4ms)17952026/09/10 12:34:06 OK 2_object_stats_trigger.sql (244.13µs)17962026/09/10 12:34:06 goose: up to current file version: 217972026/09/10 12:34:06 INFO Received uploads request method=POST path=/api/pending_closures17982026-09-10 12:34:06.990 UTC [68406] ERROR: relation "goose_db_version" does not exist at character 3617992026-09-10 12:34:06.990 UTC [68406] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026/09/10 12:34:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18012026/09/10 12:34:07 INFO Uploading 4d7m92mva2nsiy4phg3hqyhxrqwq8hyr-ca-test (144B)18022026/09/10 12:34:07 WARN Failed to register uploaded object key=log/6v24hgykx756qjgmf75knsxh6zjp0n23-ca-test.drv error="server returned 404: 404 page not found\n"18032026/09/10 12:34:07 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18042026/09/10 12:34:07 WARN Failed to register uploaded object key=4d7m92mva2nsiy4phg3hqyhxrqwq8hyr.ls error="server returned 404: 404 page not found\n"18052026/09/10 12:34:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18062026/09/10 12:34:07 INFO Signed narinfos id=1 count=118072026/09/10 12:34:07 INFO Uploading 1 narinfos18082026/09/10 12:34:07 WARN Failed to register uploaded object key=4d7m92mva2nsiy4phg3hqyhxrqwq8hyr.narinfo error="server returned 404: 404 page not found\n"18092026/09/10 12:34:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18102026/09/10 12:34:07 INFO Completed upload id=118112026/09/10 12:34:07 INFO Upload complete. (158ms)1812=== NAME TestClientCADerivations1813 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-68052-3578224089/TestClientCADerivations2675078241/001/store/4d7m92mva2nsiy4phg3hqyhxrqwq8hyr-ca-test1814 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1815 Compression: zstd1816 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1817 NarSize: 1441818 References: 1819 Deriver: /nix/var/nix/builds/nix-68052-3578224089/TestClientCADerivations2675078241/001/store/6v24hgykx756qjgmf75knsxh6zjp0n23-ca-test.drv1820 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1821 client_ca_test.go:185: Checking for realisation files in S3...1822 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1823 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18242026/09/10 12:34:07 OK 20241026095416_initial_model.sql (67.58ms)1825--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1826 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1827 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1828 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1829=== CONT TestClientErrorHandling/ServerNotAvailable18302026/09/10 12:34:07 OK 20251210153512_drop_unused_gin_index.sql (7.93ms)18312026/09/10 12:34:07 OK 20251218171726_add_pins.sql (22.69ms)1832--- PASS: TestService_ReadScope_PublicByDefault (1.77s)1833=== CONT TestClientErrorHandling/InvalidAuthToken18342026/09/10 12:34:07 OK 20260628120000_add_object_size_and_stats.sql (9.31ms)18352026/09/10 12:34:07 goose: successfully migrated database to version: 202606281200001836=== NAME TestClientCADerivations1837 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket43?endpoint=http://localhost:65274®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-68052-3578224089/TestClientCADerivations2675078241/001/store'1838 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118392026/09/10 12:34:07 OK 1_commit_pending_closure.sql (1.61ms)18402026/09/10 12:34:07 OK 2_object_stats_trigger.sql (278.42µs)18412026/09/10 12:34:07 goose: up to current file version: 218422026-09-10 12:34:07.126 UTC [68412] ERROR: relation "goose_db_version" does not exist at character 3618432026-09-10 12:34:07.126 UTC [68412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1844--- PASS: TestClientCADerivations (3.39s)1845=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token18462026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[write]1847=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18482026/09/10 12:34:07 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]1849=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1850=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18512026/09/10 12:34:07 WARN Authentication failed token_preview=eyJhbGciOi...7foGr5Rf_A token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1852--- PASS: TestService_AuthMiddleware_OIDC (2.38s)1853 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1854 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1855 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1856 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18572026/09/10 12:34:07 OK 20241026095416_initial_model.sql (36.73ms)18582026/09/10 12:34:07 OK 20251210153512_drop_unused_gin_index.sql (819.17µs)18592026/09/10 12:34:07 OK 20251218171726_add_pins.sql (10.84ms)18602026/09/10 12:34:07 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)18612026/09/10 12:34:07 goose: successfully migrated database to version: 2026062812000018622026/09/10 12:34:07 OK 1_commit_pending_closure.sql (842.67µs)18632026/09/10 12:34:07 OK 2_object_stats_trigger.sql (213.21µs)18642026/09/10 12:34:07 goose: up to current file version: 218652026/09/10 12:34:07 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-config1866=== RUN TestService_RequireScope_OIDC/builder_may_write1867=== PAUSE TestService_RequireScope_OIDC/builder_may_write1868=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1869=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1870=== RUN TestService_RequireScope_OIDC/ops_may_admin1871=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1872=== RUN TestService_RequireScope_OIDC/ops_may_not_write1873=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1874=== RUN TestService_RequireScope_OIDC/reader_may_not_write1875=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1876=== RUN TestService_RequireScope_OIDC/static_token_may_admin1877=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1878=== RUN TestService_RequireScope_OIDC/static_token_may_write1879=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1880=== RUN TestService_RequireScope_OIDC/reader_may_read1881=== PAUSE TestService_RequireScope_OIDC/reader_may_read1882=== RUN TestService_RequireScope_OIDC/writer_implies_read1883=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1884=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1885=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1886=== CONT TestService_RequireScope_OIDC/builder_may_write1887=== CONT TestService_RequireScope_OIDC/static_token_may_admin1888=== CONT TestService_RequireScope_OIDC/writer_implies_read18892026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[write]18902026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[write]1891=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1892=== CONT TestService_RequireScope_OIDC/reader_may_read1893=== CONT TestService_RequireScope_OIDC/static_token_may_write1894=== CONT TestService_RequireScope_OIDC/ops_may_not_write18952026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[read]18962026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[admin]1897=== CONT TestService_RequireScope_OIDC/reader_may_not_write1898=== CONT TestService_RequireScope_OIDC/ops_may_admin18992026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[read]1900=== CONT TestService_RequireScope_OIDC/builder_may_not_admin19012026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[admin]19022026/09/10 12:34:07 INFO OIDC auth successful provider=test scopes=[write]1903--- PASS: TestService_RequireScope_OIDC (1.74s)1904 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19142026-09-10 12:34:07.292 UTC [68418] ERROR: relation "goose_db_version" does not exist at character 3619152026-09-10 12:34:07.292 UTC [68418] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19162026/09/10 12:34:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.258451ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19172026/09/10 12:34:07 OK 20241026095416_initial_model.sql (53.35ms)19182026/09/10 12:34:07 OK 20251210153512_drop_unused_gin_index.sql (7.32ms)19192026/09/10 12:34:07 OK 20251218171726_add_pins.sql (6.07ms)19202026/09/10 12:34:07 OK 20260628120000_add_object_size_and_stats.sql (45.71ms)19212026/09/10 12:34:07 goose: successfully migrated database to version: 2026062812000019222026/09/10 12:34:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19232026/09/10 12:34:07 WARN mTLS auth: bound subjects configured but subject DN unavailable19242026/09/10 12:34:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1925--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.42s)19262026/09/10 12:34:07 OK 1_commit_pending_closure.sql (2.01ms)19272026/09/10 12:34:07 OK 2_object_stats_trigger.sql (569.29µs)19282026/09/10 12:34:07 goose: up to current file version: 219292026/09/10 12:34:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.753431ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1930--- PASS: TestService_ReadAuthMiddleware (1.27s)19312026-09-10 12:34:07.644 UTC [68419] ERROR: relation "goose_db_version" does not exist at character 3619322026-09-10 12:34:07.644 UTC [68419] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1933--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.10s)19342026/09/10 12:34:07 OK 20241026095416_initial_model.sql (75.15ms)19352026/09/10 12:34:07 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)19362026/09/10 12:34:07 OK 20251218171726_add_pins.sql (4.77ms)19372026-09-10 12:34:07.754 UTC [68420] ERROR: relation "goose_db_version" does not exist at character 3619382026-09-10 12:34:07.754 UTC [68420] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19392026/09/10 12:34:07 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)19402026/09/10 12:34:07 goose: successfully migrated database to version: 2026062812000019412026/09/10 12:34:07 OK 1_commit_pending_closure.sql (3.71ms)19422026/09/10 12:34:07 OK 2_object_stats_trigger.sql (1.05ms)19432026/09/10 12:34:07 goose: up to current file version: 219442026/09/10 12:34:07 OK 20241026095416_initial_model.sql (73.14ms)19452026/09/10 12:34:07 OK 20251210153512_drop_unused_gin_index.sql (13.75ms)19462026/09/10 12:34:07 OK 20251218171726_add_pins.sql (16.19ms)19472026/09/10 12:34:07 OK 20260628120000_add_object_size_and_stats.sql (17.16ms)19482026/09/10 12:34:07 goose: successfully migrated database to version: 2026062812000019492026/09/10 12:34:07 OK 1_commit_pending_closure.sql (5.08ms)19502026/09/10 12:34:07 OK 2_object_stats_trigger.sql (1.04ms)19512026/09/10 12:34:07 goose: up to current file version: 219522026/09/10 12:34:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=781.087258ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1953=== NAME TestOrphanedObjectsGCStressTest1954 orphaned_objects_gc_test.go:509: Stress test completed successfully:1955 orphaned_objects_gc_test.go:510: - Active objects preserved: 201956 orphaned_objects_gc_test.go:511: - Objects deleted: 2101957 orphaned_objects_gc_test.go:512: - Total GC'd: 2101958--- PASS: TestOrphanedObjectsGCStressTest (7.44s)19592026/09/10 12:34:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19602026/09/10 12:34:08 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19612026/09/10 12:34:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01962=== NAME TestClientIntegration1963 client_integration_test.go:304: Objects in database after GC:1964 client_integration_test.go:304: Successfully deleted all objects with GC --force1965--- PASS: TestClientIntegration (5.06s)19662026/09/10 12:34:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.522311596s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19672026/09/10 12:34:10 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"19682026/09/10 12:34:10 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_closures19692026/09/10 12:34:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.870177ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19702026/09/10 12:34:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.555084ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19712026/09/10 12:34:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.167722ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19722026/09/10 12:34:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.53108475s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1973--- PASS: TestClientErrorHandling (0.00s)1974 --- PASS: TestClientErrorHandling/InvalidStorePath (1.07s)1975 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.06s)1976 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.32s)1977PASS1978{"timestamp":"2026-09-10T12:34:13.39537Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:65326","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(11)"}19792026-09-10 12:34:13.481 UTC [68089] LOG: received smart shutdown request19802026-09-10 12:34:13.481 UTC [68089] LOG: background worker "logical replication launcher" (PID 68099) exited with exit code 119812026-09-10 12:34:13.488 UTC [68094] LOG: shutting down19822026-09-10 12:34:13.488 UTC [68094] LOG: checkpoint starting: shutdown immediate19832026-09-10 12:34:14.574 UTC [68094] LOG: checkpoint complete: wrote 13232 buffers (80.8%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.793 s, sync=0.291 s, total=1.087 s; sync files=17141, longest=0.001 s, average=0.001 s; distance=240173 kB, estimate=240173 kB; lsn=0/102183E0, redo lsn=0/102183E019842026-09-10 12:34:14.579 UTC [68089] LOG: database system is shut down1985Running OIDC tests...1986=== RUN TestGlobMatch1987=== PAUSE TestGlobMatch1988=== RUN TestAudienceForIssuer1989=== PAUSE TestAudienceForIssuer1990=== RUN TestValidateToken_ValidToken1991=== PAUSE TestValidateToken_ValidToken1992=== RUN TestValidateToken_WrongAudience1993=== PAUSE TestValidateToken_WrongAudience1994=== RUN TestValidateToken_Expired1995=== PAUSE TestValidateToken_Expired1996=== RUN TestValidateToken_BoundClaimsMismatch1997=== PAUSE TestValidateToken_BoundClaimsMismatch1998=== RUN TestValidateToken_BoundSubjectMismatch1999=== PAUSE TestValidateToken_BoundSubjectMismatch2000=== RUN TestValidateToken_MultipleProviders2001=== PAUSE TestValidateToken_MultipleProviders2002=== RUN TestValidateToken_NoMatchingProvider2003=== PAUSE TestValidateToken_NoMatchingProvider2004=== RUN TestValidateToken_KubernetesServiceAccount2005=== PAUSE TestValidateToken_KubernetesServiceAccount2006=== RUN TestNewValidator_KubernetesRequiresCA2007=== PAUSE TestNewValidator_KubernetesRequiresCA2008=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2009=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2010=== RUN TestScopes_LegacyProviderDefaultsToWrite2011=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2012=== RUN TestScopes_Rules2013=== PAUSE TestScopes_Rules2014=== RUN TestScopes_ConfigValidation2015=== PAUSE TestScopes_ConfigValidation2016=== CONT TestGlobMatch2017=== RUN TestGlobMatch/foo_foo2018=== CONT TestValidateToken_MultipleProviders2019=== CONT TestValidateToken_BoundSubjectMismatch2020=== CONT TestScopes_Rules2021=== CONT TestNewValidator_KubernetesRequiresCA2022=== CONT TestValidateToken_KubernetesServiceAccount2023=== CONT TestValidateToken_NoMatchingProvider2024=== PAUSE TestGlobMatch/foo_foo2025=== RUN TestGlobMatch/foo_bar2026=== PAUSE TestGlobMatch/foo_bar2027=== RUN TestGlobMatch/*_2028=== PAUSE TestGlobMatch/*_2029=== RUN TestGlobMatch/*_anything2030=== PAUSE TestGlobMatch/*_anything2031=== CONT TestScopes_LegacyProviderDefaultsToWrite2032=== CONT TestValidateToken_WrongAudience2033=== CONT TestValidateToken_BoundClaimsMismatch2034=== RUN TestGlobMatch/foo*_foo2035=== PAUSE TestGlobMatch/foo*_foo2036=== RUN TestGlobMatch/foo*_foobar2037=== PAUSE TestGlobMatch/foo*_foobar2038=== RUN TestGlobMatch/foo*_bar2039=== PAUSE TestGlobMatch/foo*_bar2040=== RUN TestGlobMatch/*bar_bar2041=== PAUSE TestGlobMatch/*bar_bar2042=== RUN TestGlobMatch/*bar_foobar2043=== PAUSE TestGlobMatch/*bar_foobar2044=== RUN TestGlobMatch/*bar_foo2045=== PAUSE TestGlobMatch/*bar_foo2046=== RUN TestGlobMatch/foo*bar_foobar2047=== PAUSE TestGlobMatch/foo*bar_foobar2048=== RUN TestGlobMatch/foo*bar_foo123bar2049=== PAUSE TestGlobMatch/foo*bar_foo123bar2050=== RUN TestGlobMatch/foo*bar_foobarbaz2051=== PAUSE TestGlobMatch/foo*bar_foobarbaz2052=== RUN TestGlobMatch/*/*_foo/bar2053=== PAUSE TestGlobMatch/*/*_foo/bar2054=== RUN TestGlobMatch/*/*_foo2055=== PAUSE TestGlobMatch/*/*_foo2056=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2057=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2058=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02059=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02060=== RUN TestGlobMatch/refs/*/main_refs/heads/main2061=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2062=== RUN TestGlobMatch/fo?_foo2063=== PAUSE TestGlobMatch/fo?_foo2064=== RUN TestGlobMatch/fo?_fo2065=== PAUSE TestGlobMatch/fo?_fo2066=== RUN TestGlobMatch/fo?_fooo2067=== PAUSE TestGlobMatch/fo?_fooo2068=== RUN TestGlobMatch/?oo_foo2069=== PAUSE TestGlobMatch/?oo_foo2070=== RUN TestGlobMatch/?oo_boo2071=== PAUSE TestGlobMatch/?oo_boo2072=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2073=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2074=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2075=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2076=== CONT TestValidateToken_Expired20772026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65508/oidc20782026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65504/oidc20792026/09/10 12:34:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:65505/oidc20802026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65506/oidc20812026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65507/oidc20822026/09/10 12:34:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:65510/oidc20832026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65512/oidc20842026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65503/oidc20852026/09/10 12:34:15 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:65513/oidc2086--- PASS: TestValidateToken_WrongAudience (0.01s)2087=== CONT TestValidateToken_ValidToken2088--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2089=== CONT TestValidateToken_KubernetesIssuerFromOwnToken20902026/09/10 12:34:15 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:655092091--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2092=== CONT TestAudienceForIssuer2093--- PASS: TestAudienceForIssuer (0.00s)2094=== CONT TestScopes_ConfigValidation2095--- PASS: TestValidateToken_Expired (0.01s)2096=== CONT TestGlobMatch/foo_foo2097=== CONT TestGlobMatch/*/*_foo/bar2098=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2099=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2100=== CONT TestGlobMatch/?oo_boo2101=== CONT TestGlobMatch/?oo_foo2102=== CONT TestGlobMatch/fo?_fooo2103=== CONT TestGlobMatch/fo?_fo2104=== CONT TestGlobMatch/fo?_foo2105=== CONT TestGlobMatch/refs/*/main_refs/heads/main2106=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02107=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2108=== CONT TestGlobMatch/*/*_foo2109=== CONT TestGlobMatch/*bar_bar2110=== CONT TestGlobMatch/foo*bar_foobarbaz2111=== CONT TestGlobMatch/foo*bar_foo123bar2112=== CONT TestGlobMatch/foo*bar_foobar2113=== CONT TestGlobMatch/*bar_foo2114=== CONT TestGlobMatch/*bar_foobar2115=== CONT TestGlobMatch/foo*_foo2116=== CONT TestGlobMatch/foo*_bar2117=== CONT TestGlobMatch/foo*_foobar2118=== CONT TestGlobMatch/*_2119=== CONT TestGlobMatch/*_anything2120=== CONT TestGlobMatch/foo_bar2121--- PASS: TestGlobMatch (0.00s)2122 --- PASS: TestGlobMatch/foo_foo (0.00s)2123 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2124 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2125 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2126 --- PASS: TestGlobMatch/?oo_boo (0.00s)2127 --- PASS: TestGlobMatch/?oo_foo (0.00s)2128 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2129 --- PASS: TestGlobMatch/fo?_fo (0.00s)2130 --- PASS: TestGlobMatch/fo?_foo (0.00s)2131 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2132 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2133 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2134 --- PASS: TestGlobMatch/*/*_foo (0.00s)2135 --- PASS: TestGlobMatch/*bar_bar (0.00s)2136 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2137 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2138 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2139 --- PASS: TestGlobMatch/*bar_foo (0.00s)2140 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2141 --- PASS: TestGlobMatch/foo*_foo (0.00s)2142 --- PASS: TestGlobMatch/foo*_bar (0.00s)2143 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2144 --- PASS: TestGlobMatch/*_ (0.00s)2145 --- PASS: TestGlobMatch/*_anything (0.00s)2146 --- PASS: TestGlobMatch/foo_bar (0.00s)21472026/09/10 12:34:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65526/oidc2148--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2149--- PASS: TestScopes_ConfigValidation (0.00s)2150--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2151--- PASS: TestValidateToken_MultipleProviders (0.01s)2152--- PASS: TestValidateToken_ValidToken (0.00s)21532026/09/10 12:34:15 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232154--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)21552026/09/10 12:34:15 http: TLS handshake error from 127.0.0.1:65523: remote error: tls: bad certificate2156--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2157--- PASS: TestScopes_Rules (0.02s)2158--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2159PASS2160Running hook tests...2161=== RUN TestSendPathsEmpty2162=== PAUSE TestSendPathsEmpty2163=== RUN TestQueueEnqueueAndFetch2164=== PAUSE TestQueueEnqueueAndFetch2165=== RUN TestQueueDeduplication2166=== PAUSE TestQueueDeduplication2167=== RUN TestQueueRemove2168=== PAUSE TestQueueRemove2169=== RUN TestQueueFetchBatchLimit2170=== PAUSE TestQueueFetchBatchLimit2171=== RUN TestQueueRetryMovesToBack2172=== PAUSE TestQueueRetryMovesToBack2173=== RUN TestQueueFetchRemoveLifecycle2174=== PAUSE TestQueueFetchRemoveLifecycle2175=== RUN TestQueueConcurrentWriters2176=== PAUSE TestQueueConcurrentWriters2177=== RUN TestQueueRemoveLargeClosure2178=== PAUSE TestQueueRemoveLargeClosure2179=== RUN TestServerClientIntegration2180=== PAUSE TestServerClientIntegration2181=== RUN TestServerQueueError2182=== PAUSE TestServerQueueError2183=== RUN TestGetListenerSocketActivation2184 server_test.go:210: === RUN TestGetListenerSocketActivation2185 --- PASS: TestGetListenerSocketActivation (0.00s)2186 PASS2187 2188--- PASS: TestGetListenerSocketActivation (0.01s)2189=== RUN TestDrainIsolatesPoisonPath2190=== PAUSE TestDrainIsolatesPoisonPath2191=== RUN TestRunNotBlockedByPoisonHead2192=== PAUSE TestRunNotBlockedByPoisonHead2193=== RUN TestDrainGivesUpWhenServerDown2194=== PAUSE TestDrainGivesUpWhenServerDown2195=== RUN TestFailedPathPrunedByLaterClosure2196=== PAUSE TestFailedPathPrunedByLaterClosure2197=== RUN TestWorkerUploadsAndRemoves2198=== PAUSE TestWorkerUploadsAndRemoves2199=== RUN TestWorkerSkipsGCdPaths2200=== PAUSE TestWorkerSkipsGCdPaths2201=== RUN TestWorkerPrunesClosureDeps2202=== PAUSE TestWorkerPrunesClosureDeps2203=== RUN TestDrainTimeout2204=== PAUSE TestDrainTimeout2205=== CONT TestSendPathsEmpty2206=== CONT TestServerQueueError2207=== CONT TestQueueRetryMovesToBack2208--- PASS: TestSendPathsEmpty (0.00s)2209=== CONT TestQueueEnqueueAndFetch2210=== CONT TestQueueRemove2211=== CONT TestQueueDeduplication2212=== CONT TestWorkerUploadsAndRemoves2213=== CONT TestDrainTimeout2214=== CONT TestWorkerPrunesClosureDeps2215=== CONT TestWorkerSkipsGCdPaths2216=== CONT TestQueueFetchBatchLimit22172026/09/10 12:34:15 ERROR Failed to queue paths error="permission denied" count=12218--- PASS: TestServerQueueError (0.00s)2219=== CONT TestQueueRemoveLargeClosure22202026/09/10 12:34:15 INFO Upload queue status pending=222212026/09/10 12:34:15 INFO Uploading batch count=22222--- PASS: TestQueueEnqueueAndFetch (0.01s)2223=== CONT TestServerClientIntegration22242026/09/10 12:34:15 INFO Upload queue status pending=222252026/09/10 12:34:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-68052-3578224089/TestWorkerSkipsGCdPaths611137445/002/nonexistent22262026/09/10 12:34:15 INFO Upload queue status pending=222272026/09/10 12:34:15 INFO Uploading batch count=122282026/09/10 12:34:15 INFO Uploading batch count=22229--- PASS: TestQueueDeduplication (0.01s)2230=== CONT TestRunNotBlockedByPoisonHead22312026/09/10 12:34:15 INFO Uploading batch count=12232--- PASS: TestQueueRemove (0.01s)2233=== CONT TestQueueConcurrentWriters2234--- PASS: TestQueueRetryMovesToBack (0.01s)2235=== CONT TestQueueFetchRemoveLifecycle2236--- PASS: TestQueueFetchBatchLimit (0.01s)2237--- PASS: TestServerClientIntegration (0.00s)2238=== CONT TestFailedPathPrunedByLaterClosure2239=== CONT TestDrainIsolatesPoisonPath22402026/09/10 12:34:15 INFO Upload queue status pending=322412026/09/10 12:34:15 INFO Uploading batch count=122422026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=122432026/09/10 12:34:15 INFO Uploading batch count=422442026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=422452026/09/10 12:34:15 INFO Uploading batch count=122462026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=122472026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainIsolatesPoisonPath1072038713/002/bbb2248--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2249=== CONT TestDrainGivesUpWhenServerDown22502026/09/10 12:34:15 INFO Uploading batch count=122512026/09/10 12:34:15 INFO Uploading batch count=122522026/09/10 12:34:15 INFO Uploading batch count=122532026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=122542026/09/10 12:34:15 INFO Uploading batch count=122552026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=122562026/09/10 12:34:15 INFO Uploading batch count=122572026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=122582026/09/10 12:34:15 ERROR Drain finished with paths left in queue remaining=12259--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22602026/09/10 12:34:15 INFO Uploading batch count=222612026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=222622026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainGivesUpWhenServerDown1112747858/002/a2263--- PASS: TestDrainIsolatesPoisonPath (0.01s)22642026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainGivesUpWhenServerDown1112747858/002/b22652026/09/10 12:34:15 INFO Uploading batch count=222662026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=222672026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainGivesUpWhenServerDown1112747858/002/c22682026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainGivesUpWhenServerDown1112747858/002/d22692026/09/10 12:34:15 INFO Uploading batch count=222702026/09/10 12:34:15 ERROR Upload failed error="upload failed" count=222712026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainGivesUpWhenServerDown1112747858/002/e22722026/09/10 12:34:15 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68052-3578224089/TestDrainGivesUpWhenServerDown1112747858/002/f22732026/09/10 12:34:15 ERROR Drain finished with paths left in queue remaining=102274--- PASS: TestDrainGivesUpWhenServerDown (0.00s)2275--- PASS: TestWorkerSkipsGCdPaths (0.03s)2276--- PASS: TestWorkerUploadsAndRemoves (0.03s)2277--- PASS: TestWorkerPrunesClosureDeps (0.03s)2278--- PASS: TestQueueRemoveLargeClosure (0.06s)2279--- PASS: TestQueueConcurrentWriters (0.13s)22802026/09/10 12:34:15 ERROR Upload failed error="context deadline exceeded" count=222812026/09/10 12:34:15 ERROR Drain finished with paths left in queue remaining=42282--- PASS: TestDrainTimeout (0.22s)22832026/09/10 12:34:16 INFO Uploading batch count=122842026/09/10 12:34:16 INFO Uploading batch count=122852026/09/10 12:34:16 INFO Uploading batch count=122862026/09/10 12:34:16 ERROR Upload failed error="upload failed" count=122872026/09/10 12:34:16 INFO Uploading batch count=122882026/09/10 12:34:16 ERROR Upload failed error="upload failed" count=122892026/09/10 12:34:16 INFO Uploading batch count=122902026/09/10 12:34:16 ERROR Upload failed error="upload failed" count=122912026/09/10 12:34:16 INFO Uploading batch count=122922026/09/10 12:34:16 ERROR Upload failed error="upload failed" count=122932026/09/10 12:34:16 ERROR Drain finished with paths left in queue remaining=12294--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2295PASS