niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.x86_64-linux.go-unit-tests` · build #188 · raw

1tribuchet: building on jamie2Running client tests...3=== RUN TestDumpPathCaseHackMatchesNix4=== RUN TestDumpPathCaseHackMatchesNix/numbered_case_variants5=== RUN TestDumpPathCaseHackMatchesNix/restored_name_ordering6--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)7 --- PASS: TestDumpPathCaseHackMatchesNix/numbered_case_variants (0.03s)8 --- PASS: TestDumpPathCaseHackMatchesNix/restored_name_ordering (0.04s)9=== RUN TestDumpPathCaseHackCollisionMatchesNix10--- PASS: TestDumpPathCaseHackCollisionMatchesNix (0.06s)11=== RUN TestDoServerRequestAttachesToken12=== PAUSE TestDoServerRequestAttachesToken13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestSetClientTLS56=== PAUSE TestSetClientTLS57=== RUN TestSetClientTLSDoesNotMutateDefaultTransport58=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport59=== RUN TestSetClientTLSErrors60=== PAUSE TestSetClientTLSErrors61=== RUN TestStaticToken62=== PAUSE TestStaticToken63=== RUN TestFileTokenReadsAndCaches64=== PAUSE TestFileTokenReadsAndCaches65=== RUN TestFileTokenMissing66=== PAUSE TestFileTokenMissing67=== RUN TestFileTokenEmpty68=== PAUSE TestFileTokenEmpty69=== RUN TestScriptTokenNoExpiryRerunsEveryCall70=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall71=== RUN TestScriptTokenCachesUntilRefresh72=== PAUSE TestScriptTokenCachesUntilRefresh73=== RUN TestScriptTokenEmptyToken74=== PAUSE TestScriptTokenEmptyToken75=== RUN TestScriptTokenBadJSON76=== PAUSE TestScriptTokenBadJSON77=== RUN TestScriptTokenScriptFails78=== PAUSE TestScriptTokenScriptFails79=== RUN TestScriptTokenEmptyCommand80=== PAUSE TestScriptTokenEmptyCommand81=== CONT TestDoServerRequestAttachesToken82=== CONT TestResolveStorePath83=== CONT TestFileTokenMissing84=== CONT TestScriptTokenCachesUntilRefresh85=== CONT TestScriptTokenNoExpiryRerunsEveryCall86=== CONT TestScriptTokenEmptyToken87--- PASS: TestFileTokenMissing (0.00s)88=== CONT TestUploadMultipart_SupersededByPeer89=== RUN TestUploadMultipart_SupersededByPeer/exists90=== PAUSE TestUploadMultipart_SupersededByPeer/exists91=== RUN TestUploadMultipart_SupersededByPeer/missing92=== PAUSE TestUploadMultipart_SupersededByPeer/missing93=== CONT TestScriptTokenEmptyCommand94--- PASS: TestScriptTokenEmptyCommand (0.00s)95=== CONT TestFileTokenReadsAndCaches96=== CONT TestFileTokenEmpty97=== CONT TestScriptTokenScriptFails98=== CONT TestEncodeNixBase32WithRealHash99--- PASS: TestEncodeNixBase32WithRealHash (0.00s)100=== CONT TestScriptTokenBadJSON101=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess102=== CONT TestRateLimiterFeedback103=== RUN TestRateLimiterFeedback/429_enables_limiter104=== CONT TestDumpPathMatchesNix105=== CONT TestShellSplitErrors106=== CONT TestEncodeNixBase321072026/09/10 03:42:08 WARN Rate limiter enabled after throttle name=server-test rate=5108=== RUN TestEncodeNixBase32/test_string_hash109=== CONT TestDumpPathWriterError110=== CONT TestPathInfoCACompatibility111=== RUN TestPathInfoCACompatibility/null_ca_field112=== PAUSE TestPathInfoCACompatibility/null_ca_field113=== CONT TestParsePathInfoJSONMultiplePaths114=== CONT TestParsePathInfoJSON115=== CONT TestPathInfoHashCompatibility116=== CONT TestGetStorePathHash117=== CONT TestDumpPathSingleFile118=== CONT TestPartSizeForNAR119=== CONT TestConvertHashToNix32120=== CONT TestSetClientTLSDoesNotMutateDefaultTransport121=== CONT TestStaticToken122--- PASS: TestResolveStorePath (0.00s)123=== CONT TestSetClientTLSErrors124=== CONT TestFilterOversizedClosures125=== PAUSE TestRateLimiterFeedback/429_enables_limiter126=== CONT TestSetClientTLS127=== CONT TestShellSplit128=== CONT TestCaseHackSuffix129=== PAUSE TestEncodeNixBase32/test_string_hash130=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== RUN TestPathInfoCACompatibility/old_string_format_-_text132=== RUN TestGetStorePathHash/valid_store_path133=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)134--- PASS: TestFileTokenReadsAndCaches (0.00s)135--- PASS: TestFileTokenEmpty (0.00s)136--- PASS: TestShellSplitErrors (0.00s)137--- PASS: TestStaticToken (0.00s)138--- PASS: TestShellSplit (0.00s)139--- PASS: TestScriptTokenEmptyToken (0.01s)140=== RUN TestPartSizeForNAR/zero_stays_at_minimum141=== RUN TestConvertHashToNix32/SRI_format_to_Nix32142=== RUN TestParsePathInfoJSON/Nix_format143=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum144=== RUN TestPartSizeForNAR/small_stays_at_minimum145=== CONT TestDoWithRetry_BodyReplayedViaGetBody146=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32147=== RUN TestEncodeNixBase32/empty_input148=== PAUSE TestEncodeNixBase32/empty_input149=== CONT TestUploadMultipart_SupersededByPeer/exists150=== RUN TestConvertHashToNix32/already_Nix32_format151=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text152=== RUN TestFilterOversizedClosures/no_limit_keeps_everything153=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything154=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped155=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped156=== RUN TestFilterOversizedClosures/all_closures_skipped157=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths159=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths160=== PAUSE TestGetStorePathHash/valid_store_path161=== PAUSE TestParsePathInfoJSON/Nix_format162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error163=== RUN TestRateLimiterFeedback/503_enables_limiter164=== PAUSE TestRateLimiterFeedback/503_enables_limiter165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== CONT TestEncodeNixBase32/test_string_hash167=== CONT TestEncodeNixBase32/empty_input168=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths169=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error170=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error171=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error172=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths173=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1742026/09/10 03:42:08 WARN Rate limiter enabled after throttle name=server-test rate=51752026/09/10 03:42:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37895176=== PAUSE TestPartSizeForNAR/small_stays_at_minimum177=== CONT TestUploadMultipart_SupersededByPeer/missing178=== PAUSE TestConvertHashToNix32/already_Nix32_format179=== RUN TestParsePathInfoJSON/Lix_format180=== PAUSE TestParsePathInfoJSON/Lix_format181--- PASS: TestScriptTokenScriptFails (0.01s)182=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter183=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive184=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error185=== PAUSE TestFilterOversizedClosures/all_closures_skipped186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon187=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum188=== RUN TestConvertHashToNix32/invalid_format189=== RUN TestSetClientTLSErrors/missing_cert_file190=== RUN TestParsePathInfoJSON/empty_input191=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum192=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts193=== PAUSE TestParsePathInfoJSON/empty_input194=== PAUSE TestConvertHashToNix32/invalid_format195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196--- PASS: TestScriptTokenBadJSON (0.01s)1972026/09/10 03:42:08 WARN Rate limiter backed off name=server-test rate=51982026/09/10 03:42:08 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37895199=== CONT TestFilterOversizedClosures/all_closures_skipped2002026/09/10 03:42:08 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50201=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2022026/09/10 03:42:08 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=2000203=== CONT TestFilterOversizedClosures/no_limit_keeps_everything204=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI205=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter206=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter207=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error208=== CONT TestGetStorePathHash/valid_store_path209=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error210=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error211=== CONT TestConvertHashToNix32/invalid_format212=== RUN TestPathInfoCACompatibility/new_structured_format_-_text213=== CONT TestConvertHashToNix32/already_Nix32_format214=== CONT TestConvertHashToNix32/SRI_format_to_Nix32215=== PAUSE TestSetClientTLSErrors/missing_cert_file216=== RUN TestSetClientTLSErrors/missing_key_file217=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts218=== RUN TestParsePathInfoJSON/whitespace_only219=== RUN TestPartSizeForNAR/1_TiB220--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)221=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter223=== CONT TestRateLimiterFeedback/429_enables_limiter224=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter225=== RUN TestSetClientTLS/rejects_connection_without_client_cert226=== CONT TestGetStorePathHash/basename_without_hyphen_should_error227=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert228=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text229=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method230=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method231=== PAUSE TestSetClientTLSErrors/missing_key_file232=== PAUSE TestParsePathInfoJSON/whitespace_only233=== RUN TestParsePathInfoJSON/invalid_JSON234=== PAUSE TestParsePathInfoJSON/invalid_JSON235=== CONT TestParsePathInfoJSON/Nix_format236=== PAUSE TestPartSizeForNAR/1_TiB237=== RUN TestPartSizeForNAR/5_TiB_S3_max_object2382026/09/10 03:42:08 WARN Rate limiter enabled after throttle name=server-test rate=5239=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object2402026/09/10 03:42:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33653241=== RUN TestPartSizeForNAR/capped_at_5_GiB242=== PAUSE TestPartSizeForNAR/capped_at_5_GiB243--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)244 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)245 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)246--- PASS: TestDoServerRequestAttachesToken (0.01s)247--- PASS: TestEncodeNixBase32 (0.00s)248 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)249 --- PASS: TestEncodeNixBase32/empty_input (0.00s)250=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512251=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter252=== CONT TestPartSizeForNAR/1_TiB253=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts254=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum2552026/09/10 03:42:08 WARN Rate limiter backed off name=server-test rate=5256=== CONT TestPartSizeForNAR/small_stays_at_minimum257=== CONT TestRateLimiterFeedback/503_enables_limiter258=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA259=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA260=== RUN TestSetClientTLS/preserves_debug_logging_transport261=== CONT TestPathInfoCACompatibility/null_ca_field262=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestPathInfoCACompatibility/new_structured_format_-_text264=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== CONT TestPathInfoCACompatibility/old_string_format_-_text2662026/09/10 03:42:08 WARN Rate limiter enabled after throttle name=server-test rate=5267=== RUN TestSetClientTLSErrors/missing_ca_file2682026/09/10 03:42:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:42619269=== PAUSE TestSetClientTLSErrors/missing_ca_file270=== CONT TestParsePathInfoJSON/whitespace_only271=== CONT TestParsePathInfoJSON/invalid_JSON272=== CONT TestParsePathInfoJSON/empty_input273=== CONT TestParsePathInfoJSON/Lix_format274=== CONT TestPartSizeForNAR/zero_stays_at_minimum275=== CONT TestPartSizeForNAR/capped_at_5_GiB276=== CONT TestPartSizeForNAR/5_TiB_S3_max_object277--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)2782026/09/10 03:42:08 WARN Rate limiter backed off name=server-test rate=5279=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512280=== PAUSE TestSetClientTLS/preserves_debug_logging_transport281=== RUN TestSetClientTLSErrors/invalid_ca_file282=== PAUSE TestSetClientTLSErrors/invalid_ca_file283=== CONT TestSetClientTLSErrors/missing_cert_file284=== CONT TestSetClientTLSErrors/missing_ca_file285=== CONT TestSetClientTLSErrors/invalid_ca_file286=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)287=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI288=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon289=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== CONT TestSetClientTLS/rejects_connection_without_client_cert291=== CONT TestSetClientTLS/preserves_debug_logging_transport292=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA293--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)294=== CONT TestSetClientTLSErrors/missing_key_file295--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)296--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)297 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)298 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)299--- PASS: TestConvertHashToNix32 (0.01s)300 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)301 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)302 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)303--- PASS: TestFilterOversizedClosures (0.01s)304 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)305 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)306 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)307--- PASS: TestParsePathInfoJSON (0.01s)308 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)309 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)310 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)311 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)312 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)313--- PASS: TestRateLimiterFeedback (0.01s)314 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)315 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)316 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)317 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)318--- PASS: TestPathInfoHashCompatibility (0.02s)319 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)320 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)321 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)322 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)323--- PASS: TestPartSizeForNAR (0.01s)324 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)325 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)326 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)328 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)329 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)330 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)331--- PASS: TestPathInfoCACompatibility (0.01s)332 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)333 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)334 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)335 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)337--- PASS: TestGetStorePathHash (0.01s)338 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)339 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)340 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)341 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)342--- PASS: TestSetClientTLSErrors (0.01s)343 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)344 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)345 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)346 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3472026/09/10 03:42:08 http: TLS handshake error from 127.0.0.1:38266: remote error: tls: bad certificate348--- PASS: TestSetClientTLS (0.02s)349 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)350 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)351 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)352--- PASS: TestDumpPathSingleFile (0.04s)353--- PASS: TestCaseHackSuffix (0.03s)354--- PASS: TestDumpPathWriterError (0.04s)355--- PASS: TestDumpPathMatchesNix (0.07s)356--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)357PASS358Running server tests...359The files belonging to this database system will be owned by user "nixbld".360This user must also own the server process.361362The database cluster will be initialized with locale "C".363The default database encoding has accordingly been set to "SQL_ASCII".364The default text search configuration will be set to "english".365366Data page checksums are enabled.367368creating directory /build/postgres3438165020/data ... ok369creating subdirectories ... ok370selecting dynamic shared memory implementation ... posix371selecting default "max_connections" ... 100372selecting default "shared_buffers" ... 128MB373selecting default time zone ... UTC374creating configuration files ... ok375running bootstrap script ... ok376performing post-bootstrap initialization ... ok377syncing data to disk ... ok378379initdb: warning: enabling "trust" authentication for local connections380initdb: 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.381382Success. You can now start the database server using:383384 pg_ctl -D /build/postgres3438165020/data -l logfile start385386/build/postgres3438165020:5432 - no response3872026-09-10 03:42:10.123 UTC [180] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3882026-09-10 03:42:10.123 UTC [180] LOG: listening on Unix socket "/build/postgres3438165020/.s.PGSQL.5432"3892026-09-10 03:42:10.128 UTC [187] LOG: database system was shut down at 2026-09-10 03:42:09 UTC3902026-09-10 03:42:10.131 UTC [180] LOG: database system is ready to accept connections391/build/postgres3438165020:5432 - accepting connections392=== RUN TestService_AuthMiddleware393=== PAUSE TestService_AuthMiddleware394=== RUN TestService_AuthMiddleware_MTLSProxyHeader395=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader396=== RUN TestService_AuthMiddleware_MTLSBoundSubjects397=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects398=== RUN TestService_ReadAuthMiddleware399=== PAUSE TestService_ReadAuthMiddleware400=== RUN TestService_AuthMiddleware_OIDC401=== PAUSE TestService_AuthMiddleware_OIDC402=== RUN TestService_RequireScope_OIDC403=== PAUSE TestService_RequireScope_OIDC404=== RUN TestService_ReadScope_PublicByDefault405=== PAUSE TestService_ReadScope_PublicByDefault406=== RUN TestCacheConfigHandler407=== PAUSE TestCacheConfigHandler408=== RUN TestCacheStatsHandler409=== PAUSE TestCacheStatsHandler410=== RUN TestClientCADerivations411=== PAUSE TestClientCADerivations412=== RUN TestClientErrorHandling413=== PAUSE TestClientErrorHandling414=== RUN TestClientIntegration415=== PAUSE TestClientIntegration416=== RUN TestClientMultipleUploads417=== PAUSE TestClientMultipleUploads418=== RUN TestClientWithDependencies419=== PAUSE TestClientWithDependencies420=== RUN TestPinProtectsFromGC421=== PAUSE TestPinProtectsFromGC422=== RUN TestResolveDBConnectionString423=== PAUSE TestResolveDBConnectionString424=== RUN TestGCAdvisoryLockBlocksConcurrentRun4252026-09-10 03:42:10.595 UTC [977] ERROR: relation "goose_db_version" does not exist at character 364262026-09-10 03:42:10.595 UTC [977] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4272026/09/10 03:42:10 OK 20241026095416_initial_model.sql (8.04ms)4282026/09/10 03:42:10 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)4292026/09/10 03:42:10 OK 20251218171726_add_pins.sql (2.03ms)4302026/09/10 03:42:10 OK 20260628120000_add_object_size_and_stats.sql (1.79ms)4312026/09/10 03:42:10 goose: successfully migrated database to version: 202606281200004322026/09/10 03:42:10 OK 1_commit_pending_closure.sql (1.39ms)4332026/09/10 03:42:10 OK 2_object_stats_trigger.sql (567.11µs)4342026/09/10 03:42:10 goose: up to current file version: 2435--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)436=== RUN TestGCBugBareHashReferences437=== PAUSE TestGCBugBareHashReferences438=== RUN TestGCMetrics439=== PAUSE TestGCMetrics440=== RUN TestGCTaskStore_StartNew441=== PAUSE TestGCTaskStore_StartNew442=== RUN TestGCTaskStore_DeduplicateSameParams443=== PAUSE TestGCTaskStore_DeduplicateSameParams444=== RUN TestGCTaskStore_ConflictDifferentParams445=== PAUSE TestGCTaskStore_ConflictDifferentParams446=== RUN TestGCTaskStore_GetEmpty447=== PAUSE TestGCTaskStore_GetEmpty448=== RUN TestGCTaskStore_GetReturnsLatest449=== PAUSE TestGCTaskStore_GetReturnsLatest450=== RUN TestGCTaskStore_CompletedAllowsNewTask451=== PAUSE TestGCTaskStore_CompletedAllowsNewTask452=== RUN TestGCTaskStore_PhaseUpdates453=== PAUSE TestGCTaskStore_PhaseUpdates454=== RUN TestGCTaskStore_Fail455=== PAUSE TestGCTaskStore_Fail456=== RUN TestGracefulShutdownDrainsInflight457=== PAUSE TestGracefulShutdownDrainsInflight458=== RUN TestService_healthCheckHandler459=== PAUSE TestService_healthCheckHandler460=== RUN TestService_readinessHandler461=== PAUSE TestService_readinessHandler462=== RUN TestGenerateLandingPage463=== PAUSE TestGenerateLandingPage464=== RUN TestCacheConfigHandlerMaxNarSize465=== PAUSE TestCacheConfigHandlerMaxNarSize466=== RUN TestCreatePendingClosureRejectsOversizedNAR467=== PAUSE TestCreatePendingClosureRejectsOversizedNAR468=== RUN TestNARDeduplicationMetadataUploadBug469=== PAUSE TestNARDeduplicationMetadataUploadBug470=== RUN TestMetricsInventory471=== PAUSE TestMetricsInventory472=== RUN TestService_NativeMTLS473=== PAUSE TestService_NativeMTLS474=== RUN TestServerTLSConfig475=== PAUSE TestServerTLSConfig476=== RUN TestMultipartCleanup477=== PAUSE TestMultipartCleanup478=== RUN TestObjectStatsTrigger479=== PAUSE TestObjectStatsTrigger480=== RUN TestOrphanedObjectsGC481=== PAUSE TestOrphanedObjectsGC482=== RUN TestOrphanedObjectsGCStressTest483=== PAUSE TestOrphanedObjectsGCStressTest484=== RUN TestResurrectedObjectNotDeleted485=== PAUSE TestResurrectedObjectNotDeleted486=== RUN TestParseSingleRange487=== PAUSE TestParseSingleRange488=== RUN TestIsValidCachePath489=== PAUSE TestIsValidCachePath490=== RUN TestReadProxyNarinfo491=== PAUSE TestReadProxyNarinfo492=== RUN TestReadProxyNarinfoAlreadyDecompressed493=== PAUSE TestReadProxyNarinfoAlreadyDecompressed494=== RUN TestReadProxyNarStreaming495=== PAUSE TestReadProxyNarStreaming496=== RUN TestReadProxy404497=== PAUSE TestReadProxy404498=== RUN TestReadProxyInvalidPath499=== PAUSE TestReadProxyInvalidPath500=== RUN TestReadProxyHead501=== PAUSE TestReadProxyHead502=== RUN TestReadProxyConditionalGet503=== PAUSE TestReadProxyConditionalGet504=== RUN TestReadProxyRootRedirectsToIndexHTML505=== PAUSE TestReadProxyRootRedirectsToIndexHTML506=== RUN TestReadProxyDisabled507=== PAUSE TestReadProxyDisabled508=== RUN TestReadRedirectNar509=== PAUSE TestReadRedirectNar510=== RUN TestReadRedirectKeepsNarinfoProxied511=== PAUSE TestReadRedirectKeepsNarinfoProxied512=== RUN TestReadProxyRangeRequest513=== PAUSE TestReadProxyRangeRequest514=== RUN TestReadRedirectUsesPublicS3URL515=== PAUSE TestReadRedirectUsesPublicS3URL516=== RUN TestRedundantMultipartUpload517=== PAUSE TestRedundantMultipartUpload518=== RUN TestCompleteMultipartUpload_ErrorButObjectExists519=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists520=== RUN TestCompletedNarNotReofferedAcrossClosures521=== PAUSE TestCompletedNarNotReofferedAcrossClosures522=== RUN TestPresignedUploadRegisteredBeforeCommit523=== PAUSE TestPresignedUploadRegisteredBeforeCommit524=== RUN TestService_Rustfstest525=== PAUSE TestService_Rustfstest526=== RUN TestParseSize527=== PAUSE TestParseSize528=== RUN TestSkippedUploadsHandler529=== PAUSE TestSkippedUploadsHandler530=== RUN TestSystemdListenerNotActivated531--- PASS: TestSystemdListenerNotActivated (0.00s)532=== RUN TestWatchdogBeatsWhenHealthy533--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)534=== RUN TestWatchdogSkipsWhenUnhealthy5352026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5362026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5372026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5382026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5392026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5402026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5412026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5422026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5432026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5442026/09/10 03:42:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"545--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)546=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle547=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle548=== RUN TestProxyWriteTimeout549=== PAUSE TestProxyWriteTimeout550=== RUN TestIsValidUploadKey551=== PAUSE TestIsValidUploadKey552=== RUN TestUploadHandlersRejectInvalidKeys553=== PAUSE TestUploadHandlersRejectInvalidKeys554=== RUN TestUploadHandlersRejectOversizedBody555=== PAUSE TestUploadHandlersRejectOversizedBody556=== RUN TestService_cleanupPendingClosuresHandler557=== PAUSE TestService_cleanupPendingClosuresHandler558=== RUN TestService_createPendingClosureHandler559=== PAUSE TestService_createPendingClosureHandler560=== RUN TestService_verifyS3Integrity561=== PAUSE TestService_verifyS3Integrity562=== RUN TestCompleteMultipartUnregistered563=== PAUSE TestCompleteMultipartUnregistered564=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT565=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT566=== CONT TestService_AuthMiddleware567=== CONT TestSkippedUploadsHandler568=== CONT TestReadProxyInvalidPath569=== CONT TestPinProtectsFromGC570=== CONT TestService_readinessHandler571=== CONT TestRedundantMultipartUpload572=== CONT TestCompleteMultipartUnregistered5732026/09/10 03:42:10 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000574=== CONT TestService_verifyS3Integrity575=== CONT TestService_createPendingClosureHandler576=== CONT TestService_cleanupPendingClosuresHandler577=== CONT TestUploadHandlersRejectOversizedBody578=== CONT TestUploadHandlersRejectInvalidKeys579=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info580=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info581=== CONT TestIsValidUploadKey582=== CONT TestProxyWriteTimeout583=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle584=== CONT TestReadRedirectUsesPublicS3URL585=== CONT TestReadProxyRangeRequest586=== CONT TestReadRedirectKeepsNarinfoProxied587=== CONT TestReadRedirectNar588=== CONT TestReadProxyDisabled589=== CONT TestReadProxyRootRedirectsToIndexHTML590=== CONT TestReadProxyConditionalGet591=== CONT TestReadProxyHead592=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT593=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal594=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal595=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key596=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key597=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key598=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key599=== RUN TestIsValidUploadKey/narinfo600=== PAUSE TestIsValidUploadKey/narinfo601=== RUN TestIsValidUploadKey/nar_zst602=== PAUSE TestIsValidUploadKey/nar_zst603=== RUN TestIsValidUploadKey/nar_xz604=== RUN TestProxyWriteTimeout/narinfo605=== PAUSE TestIsValidUploadKey/nar_xz606=== RUN TestIsValidUploadKey/nar_plain607=== CONT TestGCTaskStore_GetEmpty608=== PAUSE TestIsValidUploadKey/nar_plain609=== RUN TestIsValidUploadKey/listing610=== PAUSE TestIsValidUploadKey/listing611=== RUN TestIsValidUploadKey/build_log612=== PAUSE TestIsValidUploadKey/build_log613=== RUN TestIsValidUploadKey/build_log_home-manager_file614=== PAUSE TestIsValidUploadKey/build_log_home-manager_file615=== RUN TestIsValidUploadKey/build_log_plus_in_name616=== PAUSE TestIsValidUploadKey/build_log_plus_in_name617=== RUN TestIsValidUploadKey/build_log_question_mark618=== PAUSE TestIsValidUploadKey/build_log_question_mark619=== RUN TestIsValidUploadKey/build_log_equals620=== PAUSE TestIsValidUploadKey/build_log_equals621=== RUN TestIsValidUploadKey/realisation622=== PAUSE TestIsValidUploadKey/realisation623=== RUN TestIsValidUploadKey/realisation_plus_in_output624=== PAUSE TestIsValidUploadKey/realisation_plus_in_output625=== RUN TestIsValidUploadKey/nix-cache-info626=== PAUSE TestIsValidUploadKey/nix-cache-info627=== RUN TestIsValidUploadKey/index.html628=== PAUSE TestIsValidUploadKey/index.html629=== RUN TestIsValidUploadKey/narinfo_key,_nar_type630=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type631=== RUN TestIsValidUploadKey/nar_key,_narinfo_type632=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type633=== RUN TestIsValidUploadKey/listing_key,_narinfo_type634=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type635=== RUN TestIsValidUploadKey/traversal636=== PAUSE TestIsValidUploadKey/traversal637=== RUN TestIsValidUploadKey/traversal_nar638--- PASS: TestGCTaskStore_GetEmpty (0.00s)639=== PAUSE TestIsValidUploadKey/traversal_nar640=== RUN TestIsValidUploadKey/absolute641=== CONT TestService_healthCheckHandler642=== PAUSE TestProxyWriteTimeout/narinfo643=== RUN TestProxyWriteTimeout/1_GiB_nar644=== PAUSE TestProxyWriteTimeout/1_GiB_nar645=== RUN TestProxyWriteTimeout/10_GiB_nar646=== PAUSE TestProxyWriteTimeout/10_GiB_nar647=== RUN TestProxyWriteTimeout/unknown_size648=== PAUSE TestProxyWriteTimeout/unknown_size649=== PAUSE TestIsValidUploadKey/absolute650=== RUN TestIsValidUploadKey/empty_key651=== PAUSE TestIsValidUploadKey/empty_key652=== CONT TestGracefulShutdownDrainsInflight653=== RUN TestIsValidUploadKey/unknown_type654=== PAUSE TestIsValidUploadKey/unknown_type655=== CONT TestGCTaskStore_Fail656--- PASS: TestSkippedUploadsHandler (0.08s)657--- PASS: TestGCTaskStore_Fail (0.00s)658=== CONT TestGCTaskStore_CompletedAllowsNewTask659--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)660=== CONT TestGCTaskStore_GetReturnsLatest661--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)662=== CONT TestPresignedUploadRegisteredBeforeCommit6632026/09/10 03:42:10 INFO Starting HTTP server address=127.0.0.1:32915664=== CONT TestGCTaskStore_PhaseUpdates665--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)666=== CONT TestParseSize667--- PASS: TestParseSize (0.00s)668=== CONT TestService_Rustfstest6692026/09/10 03:42:10 INFO Shutdown signal received, draining in-flight requests timeout=10s6702026-09-10 03:42:11.023 UTC [1046] ERROR: relation "goose_db_version" does not exist at character 366712026-09-10 03:42:11.023 UTC [1046] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC672--- PASS: TestGracefulShutdownDrainsInflight (0.07s)673=== CONT TestGCTaskStore_StartNew674--- PASS: TestGCTaskStore_StartNew (0.00s)675=== CONT TestGCTaskStore_ConflictDifferentParams676--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)677=== CONT TestGCTaskStore_DeduplicateSameParams6782026-09-10 03:42:11.035 UTC [1047] ERROR: relation "goose_db_version" does not exist at character 366792026-09-10 03:42:11.035 UTC [1047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC680--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)681=== CONT TestGCBugBareHashReferences6822026-09-10 03:42:11.044 UTC [1049] ERROR: relation "goose_db_version" does not exist at character 366832026-09-10 03:42:11.044 UTC [1049] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026-09-10 03:42:11.048 UTC [1051] ERROR: relation "goose_db_version" does not exist at character 366852026-09-10 03:42:11.048 UTC [1051] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6862026-09-10 03:42:11.060 UTC [1052] ERROR: relation "goose_db_version" does not exist at character 366872026-09-10 03:42:11.060 UTC [1052] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6882026-09-10 03:42:11.063 UTC [1053] ERROR: relation "goose_db_version" does not exist at character 366892026-09-10 03:42:11.063 UTC [1053] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC690=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure691=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure692=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart693=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart694=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts695=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts696=== CONT TestGCMetrics6972026/09/10 03:42:11 OK 20241026095416_initial_model.sql (42.22ms)6982026/09/10 03:42:11 OK 20241026095416_initial_model.sql (20.93ms)6992026/09/10 03:42:11 OK 20241026095416_initial_model.sql (32ms)7002026-09-10 03:42:11.101 UTC [1058] ERROR: relation "goose_db_version" does not exist at character 367012026-09-10 03:42:11.101 UTC [1058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7022026/09/10 03:42:11 OK 20241026095416_initial_model.sql (29.54ms)7032026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)7042026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.66ms)7052026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.14ms)7062026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)7072026/09/10 03:42:11 OK 20241026095416_initial_model.sql (25.35ms)7082026/09/10 03:42:11 OK 20241026095416_initial_model.sql (52.88ms)7092026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)7102026/09/10 03:42:11 OK 20251218171726_add_pins.sql (5.19ms)7112026/09/10 03:42:11 OK 20251218171726_add_pins.sql (7.02ms)7122026/09/10 03:42:11 OK 20251218171726_add_pins.sql (5.48ms)7132026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)7142026/09/10 03:42:11 OK 20251218171726_add_pins.sql (6.73ms)7152026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.64ms)7162026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.36ms)7172026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (6.15ms)7182026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (6.24ms)7192026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007202026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007212026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)7222026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007232026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)7242026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007252026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (6.28ms)7262026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007272026/09/10 03:42:11 OK 1_commit_pending_closure.sql (3.75ms)7282026/09/10 03:42:11 OK 1_commit_pending_closure.sql (4.07ms)7292026/09/10 03:42:11 OK 1_commit_pending_closure.sql (5.41ms)7302026/09/10 03:42:11 OK 1_commit_pending_closure.sql (4.35ms)7312026/09/10 03:42:11 OK 1_commit_pending_closure.sql (5.49ms)7322026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (7.09ms)7332026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007342026-09-10 03:42:11.123 UTC [1059] ERROR: relation "goose_db_version" does not exist at character 367352026-09-10 03:42:11.123 UTC [1059] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7362026-09-10 03:42:11.124 UTC [1060] ERROR: relation "goose_db_version" does not exist at character 367372026-09-10 03:42:11.124 UTC [1060] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026/09/10 03:42:11 OK 2_object_stats_trigger.sql (4.42ms)7392026/09/10 03:42:11 goose: up to current file version: 27402026/09/10 03:42:11 OK 2_object_stats_trigger.sql (4.19ms)7412026/09/10 03:42:11 goose: up to current file version: 27422026/09/10 03:42:11 OK 2_object_stats_trigger.sql (4.28ms)7432026/09/10 03:42:11 goose: up to current file version: 27442026/09/10 03:42:11 OK 2_object_stats_trigger.sql (4.25ms)7452026/09/10 03:42:11 goose: up to current file version: 27462026/09/10 03:42:11 OK 1_commit_pending_closure.sql (4.17ms)7472026/09/10 03:42:11 OK 2_object_stats_trigger.sql (4.27ms)7482026/09/10 03:42:11 goose: up to current file version: 27492026/09/10 03:42:11 OK 20241026095416_initial_model.sql (17.39ms)7502026-09-10 03:42:11.135 UTC [1061] ERROR: relation "goose_db_version" does not exist at character 367512026-09-10 03:42:11.135 UTC [1061] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7522026/09/10 03:42:11 OK 2_object_stats_trigger.sql (10.32ms)7532026/09/10 03:42:11 goose: up to current file version: 27542026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (12.36ms)7552026/09/10 03:42:11 OK 20251218171726_add_pins.sql (7.78ms)7562026-09-10 03:42:11.149 UTC [1062] ERROR: relation "goose_db_version" does not exist at character 367572026-09-10 03:42:11.149 UTC [1062] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures7592026-09-10 03:42:11.155 UTC [1063] ERROR: relation "goose_db_version" does not exist at character 367602026-09-10 03:42:11.155 UTC [1063] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (8.09ms)7622026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007632026/09/10 03:42:11 OK 20241026095416_initial_model.sql (18.25ms)7642026/09/10 03:42:11 OK 20241026095416_initial_model.sql (18.34ms)7652026/09/10 03:42:11 OK 1_commit_pending_closure.sql (3.97ms)7662026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)7672026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.52ms)7682026/09/10 03:42:11 goose: up to current file version: 27692026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)7702026-09-10 03:42:11.163 UTC [1064] ERROR: relation "goose_db_version" does not exist at character 367712026-09-10 03:42:11.163 UTC [1064] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7722026-09-10 03:42:11.165 UTC [1065] ERROR: relation "goose_db_version" does not exist at character 367732026-09-10 03:42:11.165 UTC [1065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7742026-09-10 03:42:11.166 UTC [1066] ERROR: relation "goose_db_version" does not exist at character 367752026-09-10 03:42:11.166 UTC [1066] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026/09/10 03:42:11 OK 20251218171726_add_pins.sql (5.07ms)7772026/09/10 03:42:11 OK 20251218171726_add_pins.sql (5.67ms)7782026/09/10 03:42:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7792026/09/10 03:42:11 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst7802026-09-10 03:42:11.178 UTC [1067] ERROR: relation "goose_db_version" does not exist at character 367812026-09-10 03:42:11.178 UTC [1067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC782--- PASS: TestCompleteMultipartUnregistered (0.30s)783=== CONT TestCompletedNarNotReofferedAcrossClosures7842026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (13.55ms)7852026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007862026-09-10 03:42:11.180 UTC [1069] ERROR: relation "goose_db_version" does not exist at character 367872026-09-10 03:42:11.180 UTC [1069] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7882026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures7892026-09-10 03:42:11.181 UTC [1068] ERROR: relation "goose_db_version" does not exist at character 367902026-09-10 03:42:11.181 UTC [1068] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (14.05ms)7922026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200007932026/09/10 03:42:11 OK 20241026095416_initial_model.sql (16.63ms)7942026/09/10 03:42:11 OK 20241026095416_initial_model.sql (30.17ms)7952026/09/10 03:42:11 OK 20241026095416_initial_model.sql (23.31ms)7962026/09/10 03:42:11 OK 1_commit_pending_closure.sql (4.03ms)7972026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.95ms)7982026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)7992026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)8002026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)8012026/09/10 03:42:11 OK 2_object_stats_trigger.sql (2.34ms)8022026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.56ms)8032026/09/10 03:42:11 goose: up to current file version: 28042026/09/10 03:42:11 goose: up to current file version: 28052026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.05ms)8062026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.26ms)8072026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.85ms)8082026/09/10 03:42:11 OK 20241026095416_initial_model.sql (10.65ms)8092026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)8102026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008112026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)8122026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008132026/09/10 03:42:11 OK 20241026095416_initial_model.sql (11.1ms)8142026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)8152026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008162026/09/10 03:42:11 OK 20241026095416_initial_model.sql (9.71ms)8172026/09/10 03:42:11 OK 20241026095416_initial_model.sql (11.69ms)8182026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)8192026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.22ms)8202026-09-10 03:42:11.195 UTC [1072] ERROR: relation "goose_db_version" does not exist at character 368212026-09-10 03:42:11.195 UTC [1072] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-09-10 03:42:11.195 UTC [1074] ERROR: relation "goose_db_version" does not exist at character 368232026-09-10 03:42:11.195 UTC [1074] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026-09-10 03:42:11.195 UTC [1073] ERROR: relation "goose_db_version" does not exist at character 368252026-09-10 03:42:11.195 UTC [1073] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)8272026-09-10 03:42:11.196 UTC [1075] ERROR: relation "goose_db_version" does not exist at character 368282026-09-10 03:42:11.196 UTC [1075] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.31ms)8302026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.2ms)8312026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.72ms)8322026/09/10 03:42:11 goose: up to current file version: 28332026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.56ms)8342026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)8352026/09/10 03:42:11 OK 2_object_stats_trigger.sql (3.06ms)8362026/09/10 03:42:11 goose: up to current file version: 28372026/09/10 03:42:11 OK 20241026095416_initial_model.sql (11.95ms)8382026/09/10 03:42:11 OK 2_object_stats_trigger.sql (3ms)8392026/09/10 03:42:11 goose: up to current file version: 28402026-09-10 03:42:11.200 UTC [1076] ERROR: relation "goose_db_version" does not exist at character 368412026-09-10 03:42:11.200 UTC [1076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026/09/10 03:42:11 OK 20251218171726_add_pins.sql (5.12ms)8432026/09/10 03:42:11 OK 20251218171726_add_pins.sql (5.93ms)8442026/09/10 03:42:11 OK 20241026095416_initial_model.sql (11.36ms)8452026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.24ms)8462026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.1ms)8472026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)8482026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)8492026-09-10 03:42:11.205 UTC [1077] ERROR: relation "goose_db_version" does not exist at character 368502026-09-10 03:42:11.205 UTC [1077] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5ms)8522026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008532026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5ms)8542026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008552026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)8562026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008572026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)8582026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008592026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.74ms)8602026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.54ms)8612026/09/10 03:42:11 OK 1_commit_pending_closure.sql (3.67ms)8622026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.8ms)8632026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.65ms)8642026/09/10 03:42:11 goose: up to current file version: 28652026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.45ms)8662026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.89ms)8672026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)8682026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008692026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.68ms)8702026/09/10 03:42:11 goose: up to current file version: 28712026/09/10 03:42:11 OK 2_object_stats_trigger.sql (2.47ms)8722026/09/10 03:42:11 goose: up to current file version: 28732026/09/10 03:42:11 OK 2_object_stats_trigger.sql (2.02ms)8742026/09/10 03:42:11 goose: up to current file version: 28752026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2ms)8762026/09/10 03:42:11 OK 20241026095416_initial_model.sql (10.18ms)8772026/09/10 03:42:11 OK 20241026095416_initial_model.sql (10.59ms)8782026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)8792026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200008802026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.89ms)8812026/09/10 03:42:11 goose: up to current file version: 28822026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)8832026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)8842026/09/10 03:42:11 OK 20241026095416_initial_model.sql (13.42ms)8852026/09/10 03:42:11 OK 20241026095416_initial_model.sql (13.28ms)8862026/09/10 03:42:11 OK 20241026095416_initial_model.sql (9.39ms)8872026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.26ms)8882026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)8892026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.92ms)8902026/09/10 03:42:11 goose: up to current file version: 28912026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)8922026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)8932026/09/10 03:42:11 OK 20251218171726_add_pins.sql (2.87ms)8942026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.38ms)8952026/09/10 03:42:11 OK 20241026095416_initial_model.sql (8.95ms)8962026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.36ms)8972026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.03ms)8982026/09/10 03:42:11 OK 20251218171726_add_pins.sql (2.98ms)8992026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)9002026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3ms)9012026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009022026/09/10 03:42:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9032026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)9042026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009052026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)9062026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009072026/09/10 03:42:11 INFO Aborted multipart uploads count=09082026/09/10 03:42:11 OK 1_commit_pending_closure.sql (3.54ms)9092026/09/10 03:42:11 OK 20251218171726_add_pins.sql (4.67ms)9102026/09/10 03:42:11 OK 1_commit_pending_closure.sql (4.22ms)9112026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures9122026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)9132026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009142026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)9152026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009162026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.52ms)9172026/09/10 03:42:11 goose: up to current file version: 29182026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.44ms)9192026/09/10 03:42:11 goose: up to current file version: 29202026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.44ms)9212026/09/10 03:42:11 OK 1_commit_pending_closure.sql (1.63ms)9222026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.4ms)9232026/09/10 03:42:11 goose: up to current file version: 29242026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)9252026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009262026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.27ms)9272026/09/10 03:42:11 OK 2_object_stats_trigger.sql (934.49µs)9282026/09/10 03:42:11 goose: up to current file version: 29292026/09/10 03:42:11 OK 2_object_stats_trigger.sql (935.58µs)9302026/09/10 03:42:11 goose: up to current file version: 29312026/09/10 03:42:11 OK 1_commit_pending_closure.sql (1.78ms)9322026/09/10 03:42:11 OK 2_object_stats_trigger.sql (798.76µs)9332026/09/10 03:42:11 goose: up to current file version: 29342026/09/10 03:42:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9352026/09/10 03:42:11 INFO Aborted multipart uploads count=19362026/09/10 03:42:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9372026-09-10 03:42:11.242 UTC [1053] ERROR: Closure does not exist: id=19382026-09-10 03:42:11.242 UTC [1053] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9392026-09-10 03:42:11.242 UTC [1053] STATEMENT: -- name: CommitPendingClosure :exec940 SELECT commit_pending_closure($1::bigint)941 942--- PASS: TestService_cleanupPendingClosuresHandler (0.36s)943=== CONT TestResolveDBConnectionString944=== RUN TestResolveDBConnectionString/flag_wins945=== PAUSE TestResolveDBConnectionString/flag_wins946=== RUN TestResolveDBConnectionString/file_when_flag_empty947=== PAUSE TestResolveDBConnectionString/file_when_flag_empty948=== RUN TestResolveDBConnectionString/missing_file_is_an_error949=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error950=== RUN TestResolveDBConnectionString/PGHOST_allows_empty951=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty952=== RUN TestResolveDBConnectionString/nothing_configured953=== PAUSE TestResolveDBConnectionString/nothing_configured954=== CONT TestOrphanedObjectsGC9552026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures9562026-09-10 03:42:11.253 UTC [1098] ERROR: relation "goose_db_version" does not exist at character 369572026-09-10 03:42:11.253 UTC [1098] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9582026/09/10 03:42:11 WARN readiness check failed error="closed pool"959--- PASS: TestService_readinessHandler (0.38s)960=== CONT TestReadProxy4049612026/09/10 03:42:11 OK 20241026095416_initial_model.sql (9.52ms)962=== NAME TestPinProtectsFromGC963 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC2154308670/001/store/j5y62yfl1zwzqggr90fwi19kbikzbad5-pinned-file.txt964 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC2154308670/001/store/cg9fvsj3l812320qbcks5m7hw33jdmsi-unpinned-file.txt9652026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)9662026/09/10 03:42:11 OK 20251218171726_add_pins.sql (2.53ms)9672026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)9682026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009692026/09/10 03:42:11 OK 1_commit_pending_closure.sql (1.96ms)9702026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1ms)9712026/09/10 03:42:11 goose: up to current file version: 2972--- PASS: TestReadProxyInvalidPath (0.41s)973=== CONT TestReadProxyNarStreaming9742026-09-10 03:42:11.316 UTC [1138] ERROR: relation "goose_db_version" does not exist at character 369752026-09-10 03:42:11.316 UTC [1138] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC976--- PASS: TestReadProxyHead (0.44s)977=== CONT TestReadProxyNarinfoAlreadyDecompressed9782026/09/10 03:42:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9792026/09/10 03:42:11 OK 20241026095416_initial_model.sql (35.08ms)9802026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (32.08ms)9812026/09/10 03:42:11 OK 20251218171726_add_pins.sql (18.91ms)9822026-09-10 03:42:11.434 UTC [1177] ERROR: relation "goose_db_version" does not exist at character 369832026-09-10 03:42:11.434 UTC [1177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9842026-09-10 03:42:11.434 UTC [1159] ERROR: relation "goose_db_version" does not exist at character 369852026-09-10 03:42:11.434 UTC [1159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9862026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (12.85ms)9872026/09/10 03:42:11 goose: successfully migrated database to version: 202606281200009882026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures9892026/09/10 03:42:11 OK 1_commit_pending_closure.sql (10.27ms)9902026/09/10 03:42:11 OK 2_object_stats_trigger.sql (18.77ms)9912026/09/10 03:42:11 goose: up to current file version: 29922026/09/10 03:42:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9932026/09/10 03:42:11 INFO Uploading j5y62yfl1zwzqggr90fwi19kbikzbad5-pinned-file.txt (128B)9942026/09/10 03:42:11 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9952026/09/10 03:42:11 OK 20241026095416_initial_model.sql (20.93ms)9962026/09/10 03:42:11 WARN Failed to register uploaded object key=j5y62yfl1zwzqggr90fwi19kbikzbad5.ls error="server returned 404: 404 page not found\n"9972026/09/10 03:42:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9982026/09/10 03:42:11 INFO Signed narinfos id=1 count=19992026/09/10 03:42:11 INFO Uploading 1 narinfos10002026/09/10 03:42:11 WARN Failed to register uploaded object key=j5y62yfl1zwzqggr90fwi19kbikzbad5.narinfo error="server returned 404: 404 page not found\n"10012026/09/10 03:42:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10022026/09/10 03:42:11 OK 20241026095416_initial_model.sql (30.2ms)10032026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (17.8ms)10042026/09/10 03:42:11 INFO Completed upload id=110052026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (16.73ms)10062026/09/10 03:42:11 INFO Upload complete. (201ms)10072026/09/10 03:42:11 OK 20251218171726_add_pins.sql (15ms)10082026-09-10 03:42:11.512 UTC [1179] ERROR: relation "goose_db_version" does not exist at character 3610092026-09-10 03:42:11.512 UTC [1179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10102026/09/10 03:42:11 OK 20251218171726_add_pins.sql (14.26ms)10112026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (14.88ms)10122026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000010132026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (14.44ms)10142026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000010152026/09/10 03:42:11 OK 20241026095416_initial_model.sql (13.95ms)10162026/09/10 03:42:11 OK 1_commit_pending_closure.sql (14.39ms)10172026/09/10 03:42:11 OK 1_commit_pending_closure.sql (14.37ms)10182026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures10192026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures10202026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures10212026/09/10 03:42:11 OK 2_object_stats_trigger.sql (16.07ms)10222026/09/10 03:42:11 goose: up to current file version: 210232026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (16.47ms)10242026/09/10 03:42:11 OK 2_object_stats_trigger.sql (22.16ms)10252026/09/10 03:42:11 goose: up to current file version: 210262026/09/10 03:42:11 OK 20251218171726_add_pins.sql (22.71ms)10272026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (9.86ms)10282026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000010292026/09/10 03:42:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10302026/09/10 03:42:11 OK 1_commit_pending_closure.sql (16.71ms)10312026/09/10 03:42:11 OK 2_object_stats_trigger.sql (9.53ms)10322026/09/10 03:42:11 goose: up to current file version: 210332026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures10342026/09/10 03:42:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10352026/09/10 03:42:11 INFO Uploading cg9fvsj3l812320qbcks5m7hw33jdmsi-unpinned-file.txt (128B)10362026/09/10 03:42:11 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10372026/09/10 03:42:11 WARN Failed to register uploaded object key=cg9fvsj3l812320qbcks5m7hw33jdmsi.ls error="server returned 404: 404 page not found\n"10382026/09/10 03:42:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10392026/09/10 03:42:11 INFO Signed narinfos id=2 count=110402026/09/10 03:42:11 INFO Uploading 1 narinfos10412026/09/10 03:42:11 WARN Failed to register uploaded object key=cg9fvsj3l812320qbcks5m7hw33jdmsi.narinfo error="server returned 404: 404 page not found\n"10422026/09/10 03:42:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10432026/09/10 03:42:11 INFO Completed upload id=210442026/09/10 03:42:11 INFO Upload complete. (113ms)10452026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures1046--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.71s)1047=== CONT TestReadProxyNarinfo10482026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures10492026/09/10 03:42:11 INFO Received create pin request method=POST path=/api/pins/myapp10502026/09/10 03:42:11 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2154308670/001/store/j5y62yfl1zwzqggr90fwi19kbikzbad5-pinned-file.txt narinfo_key=j5y62yfl1zwzqggr90fwi19kbikzbad5.narinfo10512026/09/10 03:42:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures10522026/09/10 03:42:11 INFO Garbage collection started10532026/09/10 03:42:11 INFO Aborted multipart uploads count=010542026/09/10 03:42:11 WARN Force mode enabled - objects will be deleted immediately without grace period1055--- PASS: TestReadRedirectNar (0.83s)1056=== CONT TestIsValidCachePath1057=== RUN TestIsValidCachePath/narinfo1058=== PAUSE TestIsValidCachePath/narinfo1059=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1060=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1061=== RUN TestIsValidCachePath/nar_zst1062=== PAUSE TestIsValidCachePath/nar_zst1063=== RUN TestIsValidCachePath/nar_xz1064=== PAUSE TestIsValidCachePath/nar_xz1065=== RUN TestIsValidCachePath/nar_bz21066=== PAUSE TestIsValidCachePath/nar_bz21067=== RUN TestIsValidCachePath/nar_uncompressed1068=== PAUSE TestIsValidCachePath/nar_uncompressed1069=== RUN TestIsValidCachePath/ls1070=== PAUSE TestIsValidCachePath/ls1071=== RUN TestIsValidCachePath/log1072=== PAUSE TestIsValidCachePath/log1073=== RUN TestIsValidCachePath/realisation1074=== PAUSE TestIsValidCachePath/realisation1075=== RUN TestIsValidCachePath/nix-cache-info1076=== PAUSE TestIsValidCachePath/nix-cache-info1077=== RUN TestIsValidCachePath/index.html1078=== PAUSE TestIsValidCachePath/index.html1079=== RUN TestIsValidCachePath/traversal_parent1080=== PAUSE TestIsValidCachePath/traversal_parent1081=== RUN TestIsValidCachePath/traversal_in_middle1082=== PAUSE TestIsValidCachePath/traversal_in_middle1083=== RUN TestIsValidCachePath/invalid_char_e1084=== PAUSE TestIsValidCachePath/invalid_char_e1085=== RUN TestIsValidCachePath/invalid_char_u1086=== PAUSE TestIsValidCachePath/invalid_char_u1087=== RUN TestIsValidCachePath/random_path1088=== PAUSE TestIsValidCachePath/random_path1089=== RUN TestIsValidCachePath/empty1090=== PAUSE TestIsValidCachePath/empty1091=== RUN TestIsValidCachePath/leading_slash1092=== PAUSE TestIsValidCachePath/leading_slash1093=== RUN TestIsValidCachePath/wrong_extension1094=== PAUSE TestIsValidCachePath/wrong_extension1095=== RUN TestIsValidCachePath/short_hash1096=== PAUSE TestIsValidCachePath/short_hash1097=== CONT TestParseSingleRange1098=== RUN TestParseSingleRange/none1099=== PAUSE TestParseSingleRange/none1100=== RUN TestParseSingleRange/unknown_unit1101=== PAUSE TestParseSingleRange/unknown_unit1102=== RUN TestParseSingleRange/multi-range_ignored1103=== PAUSE TestParseSingleRange/multi-range_ignored1104=== RUN TestParseSingleRange/malformed_no_dash1105=== PAUSE TestParseSingleRange/malformed_no_dash1106=== RUN TestParseSingleRange/malformed_both_empty1107=== PAUSE TestParseSingleRange/malformed_both_empty1108=== RUN TestParseSingleRange/malformed_end_before_start1109=== PAUSE TestParseSingleRange/malformed_end_before_start1110=== RUN TestParseSingleRange/closed1111=== PAUSE TestParseSingleRange/closed1112=== RUN TestParseSingleRange/open-ended1113=== PAUSE TestParseSingleRange/open-ended1114=== RUN TestParseSingleRange/end_clamped_to_size1115=== PAUSE TestParseSingleRange/end_clamped_to_size1116=== RUN TestParseSingleRange/suffix1117=== PAUSE TestParseSingleRange/suffix1118=== RUN TestParseSingleRange/suffix_exceeds_size1119=== PAUSE TestParseSingleRange/suffix_exceeds_size1120=== RUN TestParseSingleRange/single_byte1121=== PAUSE TestParseSingleRange/single_byte1122=== RUN TestParseSingleRange/start_past_EOF1123=== PAUSE TestParseSingleRange/start_past_EOF1124=== RUN TestParseSingleRange/start_far_past_EOF1125=== PAUSE TestParseSingleRange/start_far_past_EOF1126=== CONT TestResurrectedObjectNotDeleted11272026/09/10 03:42:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1128--- PASS: TestService_AuthMiddleware (0.85s)1129=== CONT TestOrphanedObjectsGCStressTest11302026-09-10 03:42:11.745 UTC [1258] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-10 03:42:11.745 UTC [1258] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026/09/10 03:42:11 OK 20241026095416_initial_model.sql (9.87ms)1133--- PASS: TestReadProxyRangeRequest (0.80s)1134=== CONT TestMetricsInventory11352026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)11362026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.16ms)11372026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)11382026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000011392026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.23ms)11402026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.44ms)11412026/09/10 03:42:11 goose: up to current file version: 211422026/09/10 03:42:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1143--- PASS: TestReadRedirectUsesPublicS3URL (0.90s)1144=== CONT TestObjectStatsTrigger11452026-09-10 03:42:11.796 UTC [1269] ERROR: relation "goose_db_version" does not exist at character 3611462026-09-10 03:42:11.796 UTC [1269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1147--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.90s)1148=== CONT TestMultipartCleanup11492026-09-10 03:42:11.806 UTC [1271] ERROR: relation "goose_db_version" does not exist at character 3611502026-09-10 03:42:11.806 UTC [1271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026/09/10 03:42:11 OK 20241026095416_initial_model.sql (12.73ms)11522026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)11532026/09/10 03:42:11 OK 20241026095416_initial_model.sql (7.81ms)11542026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.24ms)1155--- PASS: TestService_Rustfstest (0.86s)1156=== CONT TestServerTLSConfig1157=== RUN TestServerTLSConfig/no_client_CA1158=== PAUSE TestServerTLSConfig/no_client_CA1159=== RUN TestServerTLSConfig/missing_CA_file1160=== PAUSE TestServerTLSConfig/missing_CA_file1161=== RUN TestServerTLSConfig/not_a_PEM_file1162=== PAUSE TestServerTLSConfig/not_a_PEM_file1163=== CONT TestService_NativeMTLS11642026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)11652026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)11662026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000011672026/09/10 03:42:11 OK 20251218171726_add_pins.sql (2.7ms)11682026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.33ms)11692026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (8.83ms)11702026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000011712026/09/10 03:42:11 OK 2_object_stats_trigger.sql (9.37ms)11722026/09/10 03:42:11 goose: up to current file version: 211732026/09/10 03:42:11 OK 1_commit_pending_closure.sql (3.42ms)11742026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.45ms)11752026/09/10 03:42:11 goose: up to current file version: 211762026-09-10 03:42:11.844 UTC [1276] ERROR: relation "goose_db_version" does not exist at character 3611772026-09-10 03:42:11.844 UTC [1276] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1178--- PASS: TestReadProxyConditionalGet (0.96s)1179=== CONT TestCacheConfigHandler1180=== RUN TestCacheConfigHandler/full_config,_no_issuer1181=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1182=== RUN TestCacheConfigHandler/no_cache_url_configured1183=== PAUSE TestCacheConfigHandler/no_cache_url_configured1184=== RUN TestCacheConfigHandler/no_signing_keys1185=== PAUSE TestCacheConfigHandler/no_signing_keys1186=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1187=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1188=== CONT TestClientWithDependencies11892026/09/10 03:42:11 OK 20241026095416_initial_model.sql (9.78ms)11902026-09-10 03:42:11.862 UTC [1277] ERROR: relation "goose_db_version" does not exist at character 3611912026-09-10 03:42:11.862 UTC [1277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)11932026/09/10 03:42:11 OK 20251218171726_add_pins.sql (2.85ms)11942026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (2.99ms)11952026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000011962026/09/10 03:42:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11972026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.79ms)11982026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures11992026/09/10 03:42:11 OK 2_object_stats_trigger.sql (2.16ms)12002026/09/10 03:42:11 goose: up to current file version: 212012026/09/10 03:42:11 OK 20241026095416_initial_model.sql (8.92ms)12022026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)12032026/09/10 03:42:11 OK 20251218171726_add_pins.sql (2.83ms)12042026-09-10 03:42:11.885 UTC [1280] ERROR: relation "goose_db_version" does not exist at character 3612052026-09-10 03:42:11.885 UTC [1280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12062026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)12072026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000012082026/09/10 03:42:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12092026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures12102026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.05ms)1211--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.93s)1212=== CONT TestClientMultipleUploads12132026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.45ms)12142026/09/10 03:42:11 goose: up to current file version: 212152026/09/10 03:42:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjE2Mzg3ZjQtZWIxZC00NTJhLTlmZDUtZWUxMjE5YjNkOTk3LmY2MDA0ZjUyLWZlYjQtNDhiMy04ZDMwLWQ5OGI1Mzk4YzRlMngxNzg5MDExNzMxMjUwOTcxOTY1 parts=1012162026/09/10 03:42:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12172026/09/10 03:42:11 INFO Completed upload id=11218--- PASS: TestReadProxyDisabled (0.94s)1219=== CONT TestClientIntegration12202026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures12212026/09/10 03:42:11 OK 20241026095416_initial_model.sql (8.42ms)12222026/09/10 03:42:11 INFO Received uploads request method=POST path=/api/pending_closures12232026/09/10 03:42:11 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12242026/09/10 03:42:11 WARN Found objects in DB but missing from S3, will re-upload count=11225--- PASS: TestService_verifyS3Integrity (1.02s)1226=== CONT TestClientErrorHandling1227=== RUN TestClientErrorHandling/InvalidStorePath1228=== PAUSE TestClientErrorHandling/InvalidStorePath1229=== RUN TestClientErrorHandling/InvalidAuthToken1230=== PAUSE TestClientErrorHandling/InvalidAuthToken1231=== RUN TestClientErrorHandling/ServerNotAvailable1232=== PAUSE TestClientErrorHandling/ServerNotAvailable1233=== CONT TestClientCADerivations12342026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)12352026-09-10 03:42:11.906 UTC [1292] ERROR: relation "goose_db_version" does not exist at character 3612362026-09-10 03:42:11.906 UTC [1292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12372026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.37ms)12382026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)12392026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000012402026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.1ms)12412026/09/10 03:42:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12422026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.57ms)12432026/09/10 03:42:11 goose: up to current file version: 21244--- PASS: TestService_healthCheckHandler (0.96s)1245=== CONT TestCacheStatsHandler12462026/09/10 03:42:11 OK 20241026095416_initial_model.sql (16.16ms)12472026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)12482026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.27ms)12492026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)12502026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000012512026/09/10 03:42:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjE2Mzg3ZjQtZWIxZC00NTJhLTlmZDUtZWUxMjE5YjNkOTk3LjQwODdjMzY5LWRlMGYtNGE2NC1hOTNkLTJmMjhjMDUxZDA0ZHgxNzg5MDExNzMxMTY0NDU0MzQw parts=1212522026-09-10 03:42:11.940 UTC [1298] ERROR: relation "goose_db_version" does not exist at character 3612532026-09-10 03:42:11.940 UTC [1298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/09/10 03:42:11 OK 1_commit_pending_closure.sql (2.47ms)1255--- PASS: TestRedundantMultipartUpload (1.06s)1256=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12572026/09/10 03:42:11 OK 2_object_stats_trigger.sql (1.72ms)12582026/09/10 03:42:11 goose: up to current file version: 21259--- PASS: TestReadRedirectKeepsNarinfoProxied (0.99s)1260=== CONT TestService_AuthMiddleware_OIDC12612026/09/10 03:42:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39829/oidc12622026/09/10 03:42:11 OK 20241026095416_initial_model.sql (10ms)12632026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)12642026/09/10 03:42:11 OK 20251218171726_add_pins.sql (3.75ms)12652026/09/10 03:42:11 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)12662026/09/10 03:42:11 goose: successfully migrated database to version: 2026062812000012672026/09/10 03:42:11 OK 1_commit_pending_closure.sql (3.34ms)12682026/09/10 03:42:11 OK 2_object_stats_trigger.sql (2.37ms)12692026/09/10 03:42:11 goose: up to current file version: 212702026-09-10 03:42:11.980 UTC [1303] ERROR: relation "goose_db_version" does not exist at character 3612712026-09-10 03:42:11.980 UTC [1303] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12722026-09-10 03:42:11.985 UTC [1304] ERROR: relation "goose_db_version" does not exist at character 3612732026-09-10 03:42:11.985 UTC [1304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12742026/09/10 03:42:11 OK 20241026095416_initial_model.sql (8.94ms)12752026-09-10 03:42:11.998 UTC [1305] ERROR: relation "goose_db_version" does not exist at character 3612762026-09-10 03:42:11.998 UTC [1305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/09/10 03:42:11 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)12782026/09/10 03:42:12 OK 20241026095416_initial_model.sql (8.58ms)12792026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)12802026/09/10 03:42:12 OK 20251218171726_add_pins.sql (3.37ms)12812026/09/10 03:42:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12822026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.78ms)12832026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)12842026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000012852026/09/10 03:42:12 INFO Aborted multipart uploads count=012862026-09-10 03:42:12.007 UTC [1307] ERROR: relation "goose_db_version" does not exist at character 3612872026-09-10 03:42:12.007 UTC [1307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12882026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)12892026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000012902026/09/10 03:42:12 OK 1_commit_pending_closure.sql (2.63ms)12912026/09/10 03:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period12922026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.92ms)12932026/09/10 03:42:12 OK 2_object_stats_trigger.sql (2.23ms)12942026/09/10 03:42:12 goose: up to current file version: 212952026/09/10 03:42:12 OK 2_object_stats_trigger.sql (980.16µs)12962026/09/10 03:42:12 goose: up to current file version: 212972026/09/10 03:42:12 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=012982026/09/10 03:42:12 INFO Vacuumed table table=pending_closures12992026/09/10 03:42:12 OK 20241026095416_initial_model.sql (8.69ms)13002026/09/10 03:42:12 INFO Vacuumed table table=pending_objects13012026/09/10 03:42:12 INFO Vacuumed table table=multipart_uploads13022026/09/10 03:42:12 INFO Vacuumed table table=closures13032026/09/10 03:42:12 INFO Vacuumed table table=objects13042026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)13052026/09/10 03:42:12 OK 20251218171726_add_pins.sql (3.12ms)13062026/09/10 03:42:12 OK 20241026095416_initial_model.sql (7.02ms)13072026-09-10 03:42:12.021 UTC [1308] ERROR: relation "goose_db_version" does not exist at character 3613082026-09-10 03:42:12.021 UTC [1308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1309--- PASS: TestGCMetrics (0.95s)1310=== CONT TestService_ReadScope_PublicByDefault13112026/09/10 03:42:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjE2Mzg3ZjQtZWIxZC00NTJhLTlmZDUtZWUxMjE5YjNkOTk3LjlkZmM5Y2IxLTFhNTAtNDllNy05ODk3LTEwMTlmM2UzNzQ1NHgxNzg5MDExNzMxNTcwODcyNTcy parts=1013122026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13132026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)13142026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)13152026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000013162026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures13172026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.84ms)13182026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.35ms)13192026/09/10 03:42:12 INFO Completed upload id=113202026/09/10 03:42:12 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013212026/09/10 03:42:12 OK 2_object_stats_trigger.sql (714.31µs)13222026/09/10 03:42:12 goose: up to current file version: 213232026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures13242026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.16ms)13252026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000013262026/09/10 03:42:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures13272026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.06ms)13282026/09/10 03:42:12 OK 2_object_stats_trigger.sql (1.08ms)13292026/09/10 03:42:12 goose: up to current file version: 213302026/09/10 03:42:12 OK 20241026095416_initial_model.sql (6.86ms)13312026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)13322026-09-10 03:42:12.034 UTC [1311] ERROR: relation "goose_db_version" does not exist at character 3613332026-09-10 03:42:12.034 UTC [1311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13342026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.64ms)13352026/09/10 03:42:12 INFO Aborted multipart uploads count=013362026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)13372026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000013382026/09/10 03:42:12 OK 1_commit_pending_closure.sql (2.23ms)13392026/09/10 03:42:12 OK 2_object_stats_trigger.sql (1.03ms)13402026/09/10 03:42:12 goose: up to current file version: 213412026/09/10 03:42:12 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=013422026/09/10 03:42:12 OK 20241026095416_initial_model.sql (8.25ms)13432026/09/10 03:42:12 INFO Vacuumed table table=pending_closures13442026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)13452026/09/10 03:42:12 INFO Vacuumed table table=pending_objects13462026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.43ms)13472026/09/10 03:42:12 INFO Vacuumed table table=multipart_uploads13482026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)13492026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000013502026/09/10 03:42:12 INFO Vacuumed table table=closures13512026/09/10 03:42:12 INFO Vacuumed table table=objects13522026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.85ms)13532026/09/10 03:42:12 OK 2_object_stats_trigger.sql (712.49µs)13542026/09/10 03:42:12 goose: up to current file version: 21355--- PASS: TestReadProxyNarStreaming (0.78s)1356=== CONT TestService_RequireScope_OIDC13572026/09/10 03:42:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39151/oidc13582026/09/10 03:42:12 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001359--- PASS: TestService_createPendingClosureHandler (1.20s)1360=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1361--- PASS: TestReadProxy404 (0.82s)1362=== CONT TestService_ReadAuthMiddleware13632026-09-10 03:42:12.089 UTC [1317] ERROR: relation "goose_db_version" does not exist at character 3613642026-09-10 03:42:12.089 UTC [1317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1365--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.79s)1366=== CONT TestCreatePendingClosureRejectsOversizedNAR13672026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures1368--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1369=== CONT TestNARDeduplicationMetadataUploadBug13702026/09/10 03:42:12 OK 20241026095416_initial_model.sql (10.21ms)13712026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)13722026/09/10 03:42:12 OK 20251218171726_add_pins.sql (3.83ms)1373--- PASS: TestReadProxyNarinfo (0.46s)1374=== CONT TestService_AuthMiddleware_MTLSProxyHeader13752026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)13762026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000013772026/09/10 03:42:12 OK 1_commit_pending_closure.sql (3.22ms)13782026/09/10 03:42:12 OK 2_object_stats_trigger.sql (2.01ms)13792026/09/10 03:42:12 goose: up to current file version: 213802026-09-10 03:42:12.156 UTC [1325] ERROR: relation "goose_db_version" does not exist at character 3613812026-09-10 03:42:12.156 UTC [1325] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13822026-09-10 03:42:12.160 UTC [1326] ERROR: relation "goose_db_version" does not exist at character 3613832026-09-10 03:42:12.160 UTC [1326] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13842026/09/10 03:42:12 OK 20241026095416_initial_model.sql (12.09ms)13852026-09-10 03:42:12.175 UTC [1327] ERROR: relation "goose_db_version" does not exist at character 3613862026-09-10 03:42:12.175 UTC [1327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13872026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)13882026/09/10 03:42:12 OK 20251218171726_add_pins.sql (3.87ms)13892026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)13902026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000013912026/09/10 03:42:12 OK 20241026095416_initial_model.sql (10.44ms)1392--- PASS: TestResurrectedObjectNotDeleted (0.47s)1393=== CONT TestCacheConfigHandlerMaxNarSize1394--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1395=== CONT TestGenerateLandingPage13962026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)13972026/09/10 03:42:12 OK 1_commit_pending_closure.sql (2.06ms)13982026/09/10 03:42:12 OK 2_object_stats_trigger.sql (914.46µs)13992026/09/10 03:42:12 goose: up to current file version: 21400--- PASS: TestGenerateLandingPage (0.00s)1401=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14022026/09/10 03:42:12 INFO Received uploads request method=POST path=/1403=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14042026/09/10 03:42:12 INFO Received complete multipart upload request method=POST path=/1405=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14062026/09/10 03:42:12 INFO Received request for more parts method=POST path=/1407=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14082026/09/10 03:42:12 INFO Received uploads request method=POST path=/1409=== CONT TestProxyWriteTimeout/narinfo1410=== CONT TestProxyWriteTimeout/unknown_size1411--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1412 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1413 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1414 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1415 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1416=== CONT TestProxyWriteTimeout/10_GiB_nar1417=== CONT TestProxyWriteTimeout/1_GiB_nar1418--- PASS: TestProxyWriteTimeout (0.08s)1419 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1420 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1421 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1422 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1423=== CONT TestIsValidUploadKey/narinfo1424=== CONT TestIsValidUploadKey/unknown_type1425=== CONT TestIsValidUploadKey/empty_key1426=== CONT TestIsValidUploadKey/absolute1427=== CONT TestIsValidUploadKey/traversal_nar1428=== CONT TestIsValidUploadKey/traversal1429=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1430=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1431=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1432=== CONT TestIsValidUploadKey/index.html1433=== CONT TestIsValidUploadKey/nix-cache-info1434=== CONT TestIsValidUploadKey/realisation_plus_in_output1435=== CONT TestIsValidUploadKey/realisation1436=== CONT TestIsValidUploadKey/build_log_equals1437=== CONT TestIsValidUploadKey/build_log_question_mark1438=== CONT TestIsValidUploadKey/build_log_plus_in_name1439=== CONT TestIsValidUploadKey/build_log_home-manager_file1440=== CONT TestIsValidUploadKey/build_log1441=== CONT TestIsValidUploadKey/listing1442=== CONT TestIsValidUploadKey/nar_plain1443=== CONT TestIsValidUploadKey/nar_xz1444=== CONT TestIsValidUploadKey/nar_zst1445--- PASS: TestIsValidUploadKey (0.08s)1446 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1447 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1448 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1449 --- PASS: TestIsValidUploadKey/absolute (0.00s)1450 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1451 --- PASS: TestIsValidUploadKey/traversal (0.00s)1452 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1453 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1454 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1455 --- PASS: TestIsValidUploadKey/index.html (0.00s)1456 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1457 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1458 --- PASS: TestIsValidUploadKey/realisation (0.00s)1459 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1460 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1461 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1462 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1463 --- PASS: TestIsValidUploadKey/build_log (0.00s)1464 --- PASS: TestIsValidUploadKey/listing (0.00s)1465 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1466 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1467 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1468=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14692026/09/10 03:42:12 INFO Received uploads request method=POST path=/14702026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.9ms)14712026/09/10 03:42:12 OK 20241026095416_initial_model.sql (8.36ms)14722026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)14732026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000014742026-09-10 03:42:12.192 UTC [1328] ERROR: relation "goose_db_version" does not exist at character 3614752026-09-10 03:42:12.192 UTC [1328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)14772026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.31ms)14782026/09/10 03:42:12 OK 2_object_stats_trigger.sql (730.47µs)14792026/09/10 03:42:12 goose: up to current file version: 214802026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.88ms)14812026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.21ms)14822026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000014832026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.85ms)1484--- PASS: TestMetricsInventory (0.44s)1485=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14862026/09/10 03:42:12 INFO Received request for more parts method=POST path=/14872026/09/10 03:42:12 OK 2_object_stats_trigger.sql (694.27µs)14882026/09/10 03:42:12 goose: up to current file version: 214892026/09/10 03:42:12 OK 20241026095416_initial_model.sql (7.01ms)14902026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (901.36µs)14912026-09-10 03:42:12.206 UTC [1329] ERROR: relation "goose_db_version" does not exist at character 3614922026-09-10 03:42:12.206 UTC [1329] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14932026/09/10 03:42:12 OK 20251218171726_add_pins.sql (1.93ms)14942026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)14952026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000014962026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.56ms)14972026/09/10 03:42:12 OK 2_object_stats_trigger.sql (971.6µs)14982026/09/10 03:42:12 goose: up to current file version: 21499--- PASS: TestGCBugBareHashReferences (1.18s)1500=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15012026/09/10 03:42:12 INFO Received complete multipart upload request method=POST path=/15022026/09/10 03:42:12 OK 20241026095416_initial_model.sql (9.34ms)15032026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)1504--- PASS: TestObjectStatsTrigger (0.43s)1505=== CONT TestResolveDBConnectionString/flag_wins1506=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1507=== CONT TestResolveDBConnectionString/nothing_configured1508=== CONT TestResolveDBConnectionString/missing_file_is_an_error1509=== CONT TestResolveDBConnectionString/file_when_flag_empty1510=== CONT TestIsValidCachePath/narinfo1511=== CONT TestIsValidCachePath/index.html1512=== CONT TestIsValidCachePath/short_hash1513=== CONT TestIsValidCachePath/wrong_extension1514=== CONT TestIsValidCachePath/leading_slash1515=== CONT TestIsValidCachePath/empty1516=== CONT TestIsValidCachePath/random_path1517=== CONT TestIsValidCachePath/invalid_char_u1518=== CONT TestIsValidCachePath/invalid_char_e1519=== CONT TestIsValidCachePath/traversal_in_middle1520=== CONT TestIsValidCachePath/traversal_parent1521=== CONT TestIsValidCachePath/nar_xz1522=== CONT TestIsValidCachePath/nar_bz21523=== CONT TestIsValidCachePath/realisation1524=== CONT TestIsValidCachePath/nix-cache-info1525=== CONT TestIsValidCachePath/nar_uncompressed1526=== CONT TestIsValidCachePath/log1527=== CONT TestIsValidCachePath/ls1528=== CONT TestIsValidCachePath/nar_zst1529=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1530--- PASS: TestIsValidCachePath (0.00s)1531 --- PASS: TestIsValidCachePath/narinfo (0.00s)1532 --- PASS: TestIsValidCachePath/index.html (0.00s)1533 --- PASS: TestIsValidCachePath/short_hash (0.00s)1534 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1535 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1536 --- PASS: TestIsValidCachePath/empty (0.00s)1537 --- PASS: TestIsValidCachePath/random_path (0.00s)1538 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1539 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1540 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1541 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1542 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1543 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1544 --- PASS: TestIsValidCachePath/realisation (0.00s)1545 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1546 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1547 --- PASS: TestIsValidCachePath/log (0.00s)1548 --- PASS: TestIsValidCachePath/ls (0.00s)1549 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1550 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1551=== CONT TestParseSingleRange/none1552=== CONT TestParseSingleRange/open-ended1553=== CONT TestParseSingleRange/start_far_past_EOF1554=== CONT TestParseSingleRange/start_past_EOF1555=== CONT TestParseSingleRange/single_byte1556=== CONT TestParseSingleRange/suffix_exceeds_size1557=== CONT TestParseSingleRange/suffix1558=== CONT TestParseSingleRange/end_clamped_to_size1559--- PASS: TestResolveDBConnectionString (0.00s)1560 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1561 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1562 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1563 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1564 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1565=== CONT TestParseSingleRange/malformed_both_empty1566=== CONT TestParseSingleRange/closed1567=== CONT TestParseSingleRange/malformed_end_before_start1568=== CONT TestParseSingleRange/multi-range_ignored1569=== CONT TestParseSingleRange/malformed_no_dash1570=== CONT TestParseSingleRange/unknown_unit1571--- PASS: TestParseSingleRange (0.00s)1572 --- PASS: TestParseSingleRange/none (0.00s)1573 --- PASS: TestParseSingleRange/open-ended (0.00s)1574 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1575 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1576 --- PASS: TestParseSingleRange/single_byte (0.00s)1577 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1578 --- PASS: TestParseSingleRange/suffix (0.00s)1579 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1580 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1581 --- PASS: TestParseSingleRange/closed (0.00s)1582 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1583 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1584 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1585 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1586=== CONT TestServerTLSConfig/no_client_CA1587=== CONT TestServerTLSConfig/not_a_PEM_file1588=== CONT TestServerTLSConfig/missing_CA_file1589--- PASS: TestServerTLSConfig (0.00s)1590 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1591 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1592 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1593=== CONT TestCacheConfigHandler/full_config,_no_issuer15942026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures1595=== CONT TestCacheConfigHandler/no_signing_keys1596=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1597=== CONT TestCacheConfigHandler/no_cache_url_configured1598=== CONT TestClientErrorHandling/InvalidStorePath1599--- PASS: TestCacheConfigHandler (0.00s)1600 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1601 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1602 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1603 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)16042026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.68ms)16052026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.42ms)16062026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000016072026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.37ms)16082026/09/10 03:42:12 OK 2_object_stats_trigger.sql (685.52µs)16092026/09/10 03:42:12 goose: up to current file version: 21610=== CONT TestClientErrorHandling/ServerNotAvailable16112026/09/10 03:42:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16122026/09/10 03:42:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1613--- PASS: TestService_NativeMTLS (0.42s)1614=== CONT TestClientErrorHandling/InvalidAuthToken16152026-09-10 03:42:12.292 UTC [1353] ERROR: relation "goose_db_version" does not exist at character 3616162026-09-10 03:42:12.292 UTC [1353] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16172026/09/10 03:42:12 OK 20241026095416_initial_model.sql (8.15ms)16182026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)16192026/09/10 03:42:12 OK 20251218171726_add_pins.sql (2.64ms)16202026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)16212026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000016222026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.45ms)16232026-09-10 03:42:12.315 UTC [1390] ERROR: relation "goose_db_version" does not exist at character 3616242026-09-10 03:42:12.315 UTC [1390] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16252026/09/10 03:42:12 OK 2_object_stats_trigger.sql (690.65µs)16262026/09/10 03:42:12 goose: up to current file version: 21627=== NAME TestClientMultipleUploads1628 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads3122361968/001/store/25f584npd7cdl91h4jbc2f5w7s7nwqsd-test-file-0.txt16292026/09/10 03:42:12 OK 20241026095416_initial_model.sql (7.71ms)16302026/09/10 03:42:12 OK 20251210153512_drop_unused_gin_index.sql (849.14µs)16312026/09/10 03:42:12 OK 20251218171726_add_pins.sql (1.92ms)16322026/09/10 03:42:12 OK 20260628120000_add_object_size_and_stats.sql (1.78ms)16332026/09/10 03:42:12 goose: successfully migrated database to version: 2026062812000016342026/09/10 03:42:12 OK 1_commit_pending_closure.sql (1.21ms)16352026/09/10 03:42:12 OK 2_object_stats_trigger.sql (1.18ms)16362026/09/10 03:42:12 goose: up to current file version: 216372026/09/10 03:42:12 INFO Received cleanup request method=DELETE path=/api/pending_closures16382026/09/10 03:42:12 INFO Aborted multipart uploads count=116392026/09/10 03:42:12 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-config1640--- PASS: TestMultipartCleanup (0.54s)1641--- PASS: TestCacheStatsHandler (0.42s)1642=== NAME TestOrphanedObjectsGC1643 orphaned_objects_gc_test.go:290: GC Test Summary:1644 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1645 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1646 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1647 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1648 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1649--- PASS: TestOrphanedObjectsGC (1.10s)1650=== NAME TestClientIntegration1651 client_integration_test.go:277: Created store path: /build/TestClientIntegration105826421/002/store/34hxqksirzk4ln48dm1qzhgmmv81qi0x-test-file.txt1652=== NAME TestClientMultipleUploads1653 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads3122361968/001/store/dkkwy1l805hf18fcrjz6358441nk993r-test-file-1.txt1654=== NAME TestClientWithDependencies1655 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies2603235949/001/store/di4294yz8xl0mqm9a86vf8s2r32b1f67-test-script16562026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures1657=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1658=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1659=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1660=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1661=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1662=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1663=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1664=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1665=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1666=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1667=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1668=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16692026/09/10 03:42:12 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]16702026/09/10 03:42:12 WARN Authentication failed token_preview=eyJhbGciOi...lg2TufScZA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]16712026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[write]1672--- PASS: TestService_AuthMiddleware_OIDC (0.42s)1673 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1674 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1675 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1676 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)16772026/09/10 03:42:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1678=== NAME TestClientMultipleUploads1679 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads3122361968/001/store/1nalz2ccyyzghpym4z0fs1nhnxk2lamb-test-file-2.txt1680=== NAME TestClientWithDependencies1681 client_integration_test.go:596: Found 1 dependencies (including self)16822026/09/10 03:42:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjE2Mzg3ZjQtZWIxZC00NTJhLTlmZDUtZWUxMjE5YjNkOTk3LjNhNGEzMjgzLTAyZDgtNDAzOS1hNDA5LTZiZmFkYTE3Y2ZmOHgxNzg5MDExNzMyMzYzNjI3MTEx16832026/09/10 03:42:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjE2Mzg3ZjQtZWIxZC00NTJhLTlmZDUtZWUxMjE5YjNkOTk3LjNhNGEzMjgzLTAyZDgtNDAzOS1hNDA5LTZiZmFkYTE3Y2ZmOHgxNzg5MDExNzMyMzYzNjI3MTEx parts=11684--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.45s)1685--- PASS: TestService_ReadScope_PublicByDefault (0.37s)16862026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1687=== NAME TestClientCADerivations1688 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations441705540/001/store/vrn6jb1q1svxbwxvb7p1f62swmv2axcs-ca-test1689=== RUN TestService_RequireScope_OIDC/builder_may_write1690=== PAUSE TestService_RequireScope_OIDC/builder_may_write1691=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1692=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1693=== RUN TestService_RequireScope_OIDC/ops_may_admin1694=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1695=== RUN TestService_RequireScope_OIDC/ops_may_not_write1696=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1697=== RUN TestService_RequireScope_OIDC/reader_may_not_write1698=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1699=== RUN TestService_RequireScope_OIDC/static_token_may_admin1700=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1701=== RUN TestService_RequireScope_OIDC/static_token_may_write1702=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1703=== RUN TestService_RequireScope_OIDC/reader_may_read1704=== PAUSE TestService_RequireScope_OIDC/reader_may_read1705=== RUN TestService_RequireScope_OIDC/writer_implies_read1706=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1707=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1708=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1709=== CONT TestService_RequireScope_OIDC/builder_may_write1710=== CONT TestService_RequireScope_OIDC/static_token_may_admin1711=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1712=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1713=== CONT TestService_RequireScope_OIDC/ops_may_admin1714=== CONT TestService_RequireScope_OIDC/ops_may_not_write1715=== CONT TestService_RequireScope_OIDC/reader_may_read1716=== CONT TestService_RequireScope_OIDC/writer_implies_read1717=== CONT TestService_RequireScope_OIDC/reader_may_not_write1718=== CONT TestService_RequireScope_OIDC/static_token_may_write17192026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[write]17202026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[read]17212026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[admin]17222026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[admin]17232026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[write]17242026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[write]17252026/09/10 03:42:12 INFO OIDC auth successful provider=test scopes=[read]1726--- PASS: TestService_RequireScope_OIDC (0.35s)1727 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1728 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1729 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1730 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1731 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1732 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1733 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1734 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1735 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1736 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)17372026/09/10 03:42:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17382026/09/10 03:42:12 WARN mTLS auth: bound subjects configured but subject DN unavailable17392026/09/10 03:42:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1740--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.35s)17412026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures1742--- PASS: TestService_ReadAuthMiddleware (0.35s)17432026/09/10 03:42:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17442026/09/10 03:42:12 INFO Uploading 34hxqksirzk4ln48dm1qzhgmmv81qi0x-test-file.txt (152B)17452026/09/10 03:42:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.181901ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1746=== NAME TestClientCADerivations1747 client_ca_test.go:139: Found 1 dependencies (including self)17482026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17492026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17502026/09/10 03:42:12 WARN Failed to register uploaded object key=34hxqksirzk4ln48dm1qzhgmmv81qi0x.ls error="server returned 404: 404 page not found\n"17512026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17522026/09/10 03:42:12 INFO Signed narinfos id=1 count=117532026/09/10 03:42:12 INFO Uploading 1 narinfos17542026/09/10 03:42:12 WARN Failed to register uploaded object key=34hxqksirzk4ln48dm1qzhgmmv81qi0x.narinfo error="server returned 404: 404 page not found\n"17552026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17562026/09/10 03:42:12 INFO Completed upload id=117572026/09/10 03:42:12 INFO Upload complete. (75ms)17582026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17592026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures1760=== NAME TestClientIntegration1761 client_integration_test.go:293: Retrieved narinfo from S3:1762 StorePath: /build/TestClientIntegration105826421/002/store/34hxqksirzk4ln48dm1qzhgmmv81qi0x-test-file.txt1763 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1764 Compression: zstd1765 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11766 NarSize: 1521767 References: 1768 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11769 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1770 client_integration_test.go:294: Decompressed .ls content (64 bytes):1771 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1772 client_integration_test.go:297: Testing garbage collection...17732026/09/10 03:42:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17742026/09/10 03:42:12 INFO Uploading di4294yz8xl0mqm9a86vf8s2r32b1f67-test-script (136B)17752026/09/10 03:42:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17762026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17772026/09/10 03:42:12 WARN Failed to register uploaded object key=log/sflwnqqyw1b40p1401z7sdj9dfrh0ill-test-script.drv error="server returned 404: 404 page not found\n"17782026/09/10 03:42:12 WARN Failed to register uploaded object key=di4294yz8xl0mqm9a86vf8s2r32b1f67.ls error="server returned 404: 404 page not found\n"17792026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17802026/09/10 03:42:12 INFO Signed narinfos id=1 count=117812026/09/10 03:42:12 INFO Uploading 1 narinfos17822026/09/10 03:42:12 WARN Failed to register uploaded object key=di4294yz8xl0mqm9a86vf8s2r32b1f67.narinfo error="server returned 404: 404 page not found\n"17832026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17842026/09/10 03:42:12 INFO Completed upload id=117852026/09/10 03:42:12 INFO Upload complete. (52ms)1786--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)17872026/09/10 03:42:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjE2Mzg3ZjQtZWIxZC00NTJhLTlmZDUtZWUxMjE5YjNkOTk3LmQwMDk5NjBjLWM2ZTQtNDQ4Yy1iMjRiLWMzY2I5YmYzNjhiNXgxNzg5MDExNzMyMDI3MzU3NDU2 parts=121788=== NAME TestClientWithDependencies1789 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2603235949/001/store) requires matching store prefix17902026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures1791--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.29s)1792--- PASS: TestClientWithDependencies (0.61s)17932026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures17942026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures17952026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures17962026/09/10 03:42:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17972026/09/10 03:42:12 INFO Uploading 25f584npd7cdl91h4jbc2f5w7s7nwqsd-test-file-0.txt (160B)17982026/09/10 03:42:12 INFO Uploading dkkwy1l805hf18fcrjz6358441nk993r-test-file-1.txt (160B)17992026/09/10 03:42:12 INFO Uploading 1nalz2ccyyzghpym4z0fs1nhnxk2lamb-test-file-2.txt (160B)18002026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18012026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18022026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18032026/09/10 03:42:12 WARN Failed to register uploaded object key=25f584npd7cdl91h4jbc2f5w7s7nwqsd.ls error="server returned 404: 404 page not found\n"18042026/09/10 03:42:12 WARN Failed to register uploaded object key=dkkwy1l805hf18fcrjz6358441nk993r.ls error="server returned 404: 404 page not found\n"18052026/09/10 03:42:12 WARN Failed to register uploaded object key=1nalz2ccyyzghpym4z0fs1nhnxk2lamb.ls error="server returned 404: 404 page not found\n"18062026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18072026/09/10 03:42:12 INFO Signed narinfos id=2 count=118082026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18092026/09/10 03:42:12 INFO Signed narinfos id=3 count=118102026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18112026/09/10 03:42:12 INFO Signed narinfos id=1 count=118122026/09/10 03:42:12 INFO Uploading 3 narinfos18132026/09/10 03:42:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures18142026/09/10 03:42:12 INFO Garbage collection started18152026/09/10 03:42:12 WARN Failed to register uploaded object key=dkkwy1l805hf18fcrjz6358441nk993r.narinfo error="server returned 404: 404 page not found\n"18162026/09/10 03:42:12 WARN Failed to register uploaded object key=1nalz2ccyyzghpym4z0fs1nhnxk2lamb.narinfo error="server returned 404: 404 page not found\n"1817=== NAME TestNARDeduplicationMetadataUploadBug1818 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1903737178/001/store/895k3mqg3ffwizw77j2f3lgzd94fq8q2-file1.txt18192026/09/10 03:42:12 WARN Failed to register uploaded object key=25f584npd7cdl91h4jbc2f5w7s7nwqsd.narinfo error="server returned 404: 404 page not found\n"18202026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18212026/09/10 03:42:12 INFO Completed upload id=118222026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18232026/09/10 03:42:12 INFO Aborted multipart uploads count=018242026/09/10 03:42:12 INFO Completed upload id=218252026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18262026/09/10 03:42:12 INFO Completed upload id=318272026/09/10 03:42:12 INFO Upload complete. (81ms)1828=== NAME TestClientMultipleUploads1829 client_integration_test.go:350: Uploaded 3 paths in 111.628645ms18302026/09/10 03:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period1831--- PASS: TestClientMultipleUploads (0.61s)18322026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18332026/09/10 03:42:12 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=018342026/09/10 03:42:12 INFO Vacuumed table table=pending_closures18352026/09/10 03:42:12 INFO Vacuumed table table=pending_objects18362026/09/10 03:42:12 INFO Vacuumed table table=multipart_uploads18372026/09/10 03:42:12 INFO Vacuumed table table=closures18382026/09/10 03:42:12 INFO Vacuumed table table=objects18392026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures18402026/09/10 03:42:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18412026/09/10 03:42:12 INFO Uploading vrn6jb1q1svxbwxvb7p1f62swmv2axcs-ca-test (144B)18422026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18432026/09/10 03:42:12 WARN Failed to register uploaded object key=log/w2m2d36b2sc5b50xbhhsqns78jxdskj4-ca-test.drv error="server returned 404: 404 page not found\n"18442026/09/10 03:42:12 WARN Failed to register uploaded object key=vrn6jb1q1svxbwxvb7p1f62swmv2axcs.ls error="server returned 404: 404 page not found\n"18452026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18462026/09/10 03:42:12 INFO Signed narinfos id=1 count=118472026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18482026/09/10 03:42:12 INFO Uploading 1 narinfos18492026/09/10 03:42:12 WARN Failed to register uploaded object key=vrn6jb1q1svxbwxvb7p1f62swmv2axcs.narinfo error="server returned 404: 404 page not found\n"18502026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18512026/09/10 03:42:12 INFO Completed upload id=118522026/09/10 03:42:12 INFO Upload complete. (82ms)1853=== NAME TestClientCADerivations1854 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations441705540/001/store/vrn6jb1q1svxbwxvb7p1f62swmv2axcs-ca-test1855 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1856 Compression: zstd1857 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1858 NarSize: 1441859 References: 1860 Deriver: /build/TestClientCADerivations441705540/001/store/w2m2d36b2sc5b50xbhhsqns78jxdskj4-ca-test.drv1861 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1862 client_ca_test.go:185: Checking for realisation files in S3...1863 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1864 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18652026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures18662026/09/10 03:42:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18672026/09/10 03:42:12 INFO Uploading 895k3mqg3ffwizw77j2f3lgzd94fq8q2-file1.txt (160B)18682026/09/10 03:42:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18692026/09/10 03:42:12 WARN Failed to register uploaded object key=895k3mqg3ffwizw77j2f3lgzd94fq8q2.ls error="server returned 404: 404 page not found\n"18702026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18712026/09/10 03:42:12 INFO Signed narinfos id=1 count=118722026/09/10 03:42:12 INFO Uploading 1 narinfos18732026/09/10 03:42:12 WARN Failed to register uploaded object key=895k3mqg3ffwizw77j2f3lgzd94fq8q2.narinfo error="server returned 404: 404 page not found\n"18742026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18752026/09/10 03:42:12 INFO Completed upload id=118762026/09/10 03:42:12 INFO Upload complete. (71ms)1877=== NAME TestNARDeduplicationMetadataUploadBug1878 metadata_upload_test.go:54: Retrieved narinfo from S3:1879 StorePath: /build/TestNARDeduplicationMetadataUploadBug1903737178/001/store/895k3mqg3ffwizw77j2f3lgzd94fq8q2-file1.txt1880 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1881 Compression: zstd1882 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1883 NarSize: 1601884 References: 1885 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1886 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1887 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1888 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18892026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1890 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1903737178/001/store/s53x4jgqzix0a160ir7vxcp087ffy8bw-file2.txt18912026/09/10 03:42:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=386.026933ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18922026/09/10 03:42:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18932026/09/10 03:42:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1894=== NAME TestClientCADerivations1895 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1896 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1897 error: binary cache 's3://bucket41?endpoint=http://localhost:42133&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations441705540/001/store'1898 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11899--- PASS: TestClientCADerivations (0.79s)19002026/09/10 03:42:12 INFO Received uploads request method=POST path=/api/pending_closures19012026/09/10 03:42:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19022026/09/10 03:42:12 WARN Failed to register uploaded object key=s53x4jgqzix0a160ir7vxcp087ffy8bw.ls error="server returned 404: 404 page not found\n"19032026/09/10 03:42:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19042026/09/10 03:42:12 INFO Signed narinfos id=2 count=119052026/09/10 03:42:12 INFO Uploading 1 narinfos19062026/09/10 03:42:12 WARN Failed to register uploaded object key=s53x4jgqzix0a160ir7vxcp087ffy8bw.narinfo error="server returned 404: 404 page not found\n"19072026/09/10 03:42:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19082026/09/10 03:42:12 INFO Completed upload id=219092026/09/10 03:42:12 INFO Upload complete. (73ms)1910=== NAME TestNARDeduplicationMetadataUploadBug1911 metadata_upload_test.go:76: Retrieved narinfo from S3:1912 StorePath: /build/TestNARDeduplicationMetadataUploadBug1903737178/001/store/s53x4jgqzix0a160ir7vxcp087ffy8bw-file2.txt1913 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1914 Compression: zstd1915 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1916 NarSize: 1601917 References: 1918 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1919 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1920 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1921 {"version":1,"root":{"type":"regular","size":44}}1922--- PASS: TestNARDeduplicationMetadataUploadBug (0.63s)1923--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)1924 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1925 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1926 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.58s)19272026/09/10 03:42:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.237687ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19282026/09/10 03:42:13 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=019292026/09/10 03:42:13 INFO Vacuumed table table=pending_closures19302026/09/10 03:42:13 INFO Vacuumed table table=pending_objects19312026/09/10 03:42:13 INFO Vacuumed table table=multipart_uploads19322026/09/10 03:42:13 INFO Vacuumed table table=closures19332026/09/10 03:42:13 INFO Vacuumed table table=objects1934=== NAME TestOrphanedObjectsGCStressTest1935 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1936 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1937 orphaned_objects_gc_test.go:509: Stress test completed successfully:1938 orphaned_objects_gc_test.go:510: - Active objects preserved: 201939 orphaned_objects_gc_test.go:511: - Objects deleted: 2101940 orphaned_objects_gc_test.go:512: - Total GC'd: 2101941--- PASS: TestOrphanedObjectsGCStressTest (1.85s)19422026/09/10 03:42:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01943=== NAME TestPinProtectsFromGC1944 client_integration_test.go:711: Pin successfully protected closure from garbage collection1945--- PASS: TestPinProtectsFromGC (2.83s)19462026/09/10 03:42:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.610313524s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19472026/09/10 03:42:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01948=== NAME TestClientIntegration1949 client_integration_test.go:304: Objects in database after GC:1950 client_integration_test.go:304: Successfully deleted all objects with GC --force1951--- PASS: TestClientIntegration (2.59s)19522026/09/10 03:42:15 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"19532026/09/10 03:42:15 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_closures19542026/09/10 03:42:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.418658ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19552026/09/10 03:42:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.382837ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19562026/09/10 03:42:16 WARN Rate limiter enabled after throttle name=s3-test rate=519572026/09/10 03:42:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1958=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1959 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101960 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001961--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.20s)19622026/09/10 03:42:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=781.576089ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19632026/09/10 03:42:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.673231195s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1964--- PASS: TestClientErrorHandling (0.00s)1965 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)1966 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)1967 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.40s)1968PASS19692026-09-10 03:42:18.856 UTC [180] LOG: received smart shutdown request19702026-09-10 03:42:18.884 UTC [180] LOG: background worker "logical replication launcher" (PID 190) exited with exit code 119712026-09-10 03:42:18.896 UTC [185] LOG: shutting down19722026-09-10 03:42:18.914 UTC [185] LOG: checkpoint starting: shutdown immediate19732026-09-10 03:42:20.612 UTC [185] LOG: checkpoint complete: wrote 10985 buffers (67.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 14 recycled; write=0.225 s, sync=1.357 s, total=1.716 s; sync files=17141, longest=0.002 s, average=0.001 s; distance=236082 kB, estimate=236082 kB; lsn=0/FDF27E8, redo lsn=0/FDF27E819742026-09-10 03:42:20.705 UTC [180] LOG: database system is shut down1975Running OIDC tests...1976=== RUN TestGlobMatch1977=== PAUSE TestGlobMatch1978=== RUN TestAudienceForIssuer1979=== PAUSE TestAudienceForIssuer1980=== RUN TestValidateToken_ValidToken1981=== PAUSE TestValidateToken_ValidToken1982=== RUN TestValidateToken_WrongAudience1983=== PAUSE TestValidateToken_WrongAudience1984=== RUN TestValidateToken_Expired1985=== PAUSE TestValidateToken_Expired1986=== RUN TestValidateToken_BoundClaimsMismatch1987=== PAUSE TestValidateToken_BoundClaimsMismatch1988=== RUN TestValidateToken_BoundSubjectMismatch1989=== PAUSE TestValidateToken_BoundSubjectMismatch1990=== RUN TestValidateToken_MultipleProviders1991=== PAUSE TestValidateToken_MultipleProviders1992=== RUN TestValidateToken_NoMatchingProvider1993=== PAUSE TestValidateToken_NoMatchingProvider1994=== RUN TestValidateToken_KubernetesServiceAccount1995=== PAUSE TestValidateToken_KubernetesServiceAccount1996=== RUN TestNewValidator_KubernetesRequiresCA1997=== PAUSE TestNewValidator_KubernetesRequiresCA1998=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1999=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2000=== RUN TestScopes_LegacyProviderDefaultsToWrite2001=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2002=== RUN TestScopes_Rules2003=== PAUSE TestScopes_Rules2004=== RUN TestScopes_ConfigValidation2005=== PAUSE TestScopes_ConfigValidation2006=== CONT TestGlobMatch2007=== CONT TestValidateToken_NoMatchingProvider2008=== CONT TestScopes_LegacyProviderDefaultsToWrite2009=== RUN TestGlobMatch/foo_foo2010=== PAUSE TestGlobMatch/foo_foo2011=== CONT TestValidateToken_MultipleProviders2012=== RUN TestGlobMatch/foo_bar2013=== PAUSE TestGlobMatch/foo_bar2014=== RUN TestGlobMatch/*_2015=== PAUSE TestGlobMatch/*_2016=== RUN TestGlobMatch/*_anything2017=== PAUSE TestGlobMatch/*_anything2018=== RUN TestGlobMatch/foo*_foo2019=== PAUSE TestGlobMatch/foo*_foo2020=== RUN TestGlobMatch/foo*_foobar2021=== PAUSE TestGlobMatch/foo*_foobar2022=== RUN TestGlobMatch/foo*_bar2023=== PAUSE TestGlobMatch/foo*_bar2024=== RUN TestGlobMatch/*bar_bar2025=== PAUSE TestGlobMatch/*bar_bar2026=== RUN TestGlobMatch/*bar_foobar2027=== PAUSE TestGlobMatch/*bar_foobar2028=== RUN TestGlobMatch/*bar_foo2029=== PAUSE TestGlobMatch/*bar_foo2030=== RUN TestGlobMatch/foo*bar_foobar2031=== PAUSE TestGlobMatch/foo*bar_foobar2032=== RUN TestGlobMatch/foo*bar_foo123bar2033=== PAUSE TestGlobMatch/foo*bar_foo123bar2034=== RUN TestGlobMatch/foo*bar_foobarbaz2035=== PAUSE TestGlobMatch/foo*bar_foobarbaz2036=== RUN TestGlobMatch/*/*_foo/bar2037=== CONT TestValidateToken_BoundSubjectMismatch2038=== CONT TestValidateToken_Expired2039=== CONT TestValidateToken_WrongAudience2040=== CONT TestValidateToken_ValidToken2041=== CONT TestAudienceForIssuer2042--- PASS: TestAudienceForIssuer (0.00s)2043=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2044=== CONT TestScopes_ConfigValidation2045=== CONT TestValidateToken_KubernetesServiceAccount2046=== CONT TestScopes_Rules2047=== CONT TestNewValidator_KubernetesRequiresCA2048=== PAUSE TestGlobMatch/*/*_foo/bar2049=== CONT TestValidateToken_BoundClaimsMismatch2050=== RUN TestGlobMatch/*/*_foo2051=== PAUSE TestGlobMatch/*/*_foo2052=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2053=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2054=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02055=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02056=== RUN TestGlobMatch/refs/*/main_refs/heads/main2057=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2058=== RUN TestGlobMatch/fo?_foo2059=== PAUSE TestGlobMatch/fo?_foo2060=== RUN TestGlobMatch/fo?_fo2061=== PAUSE TestGlobMatch/fo?_fo2062=== RUN TestGlobMatch/fo?_fooo2063=== PAUSE TestGlobMatch/fo?_fooo2064=== RUN TestGlobMatch/?oo_foo2065=== PAUSE TestGlobMatch/?oo_foo2066=== RUN TestGlobMatch/?oo_boo2067=== PAUSE TestGlobMatch/?oo_boo2068=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2069=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2070=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2071=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2072=== CONT TestGlobMatch/foo_foo2073=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2074=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2075=== CONT TestGlobMatch/?oo_boo2076=== CONT TestGlobMatch/foo*bar_foobar2077=== CONT TestGlobMatch/foo*bar_foo123bar2078=== CONT TestGlobMatch/fo?_fo2079=== CONT TestGlobMatch/foo*_foobar2080=== CONT TestGlobMatch/foo*_foo2081=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2082=== CONT TestGlobMatch/?oo_foo2083=== CONT TestGlobMatch/fo?_fooo2084=== CONT TestGlobMatch/*bar_foo2085=== CONT TestGlobMatch/*bar_bar2086=== CONT TestGlobMatch/fo?_foo2087=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02088=== CONT TestGlobMatch/*/*_foo/bar2089=== CONT TestGlobMatch/*_anything2090=== CONT TestGlobMatch/*/*_foo2091=== CONT TestGlobMatch/refs/*/main_refs/heads/main2092=== CONT TestGlobMatch/*_2093=== CONT TestGlobMatch/foo_bar2094=== CONT TestGlobMatch/foo*bar_foobarbaz2095=== CONT TestGlobMatch/*bar_foobar2096=== CONT TestGlobMatch/foo*_bar2097--- PASS: TestScopes_ConfigValidation (0.01s)2098--- PASS: TestGlobMatch (0.01s)2099 --- PASS: TestGlobMatch/foo_foo (0.00s)2100 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2101 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2102 --- PASS: TestGlobMatch/?oo_boo (0.00s)2103 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2104 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2105 --- PASS: TestGlobMatch/fo?_fo (0.00s)2106 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2107 --- PASS: TestGlobMatch/foo*_foo (0.00s)2108 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2109 --- PASS: TestGlobMatch/?oo_foo (0.00s)2110 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2111 --- PASS: TestGlobMatch/*bar_foo (0.00s)2112 --- PASS: TestGlobMatch/*bar_bar (0.00s)2113 --- PASS: TestGlobMatch/fo?_foo (0.00s)2114 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2115 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2116 --- PASS: TestGlobMatch/*_anything (0.00s)2117 --- PASS: TestGlobMatch/*/*_foo (0.00s)2118 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2119 --- PASS: TestGlobMatch/*_ (0.00s)2120 --- PASS: TestGlobMatch/foo_bar (0.00s)2121 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2122 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2123 --- PASS: TestGlobMatch/foo*_bar (0.00s)21242026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36897/oidc21252026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35835/oidc21262026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46425/oidc21272026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36979/oidc21282026/09/10 03:42:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321292026/09/10 03:42:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42155/oidc21302026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35853/oidc21312026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37231/oidc21322026/09/10 03:42:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44099/oidc21332026/09/10 03:42:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35091/oidc21342026/09/10 03:42:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37823/oidc2135--- PASS: TestValidateToken_ValidToken (0.02s)2136--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2137--- PASS: TestValidateToken_WrongAudience (0.02s)2138--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2139--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2140--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2141--- PASS: TestValidateToken_Expired (0.02s)21422026/09/10 03:42:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:367152143--- PASS: TestValidateToken_MultipleProviders (0.02s)2144--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2145--- PASS: TestScopes_Rules (0.02s)2146--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)21472026/09/10 03:42:21 http: TLS handshake error from 127.0.0.1:41986: remote error: tls: bad certificate2148--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2149PASS2150Running hook tests...2151=== RUN TestSendPathsEmpty2152=== PAUSE TestSendPathsEmpty2153=== RUN TestQueueEnqueueAndFetch2154=== PAUSE TestQueueEnqueueAndFetch2155=== RUN TestQueueDeduplication2156=== PAUSE TestQueueDeduplication2157=== RUN TestQueueRemove2158=== PAUSE TestQueueRemove2159=== RUN TestQueueFetchBatchLimit2160=== PAUSE TestQueueFetchBatchLimit2161=== RUN TestQueueRetryMovesToBack2162=== PAUSE TestQueueRetryMovesToBack2163=== RUN TestQueueFetchRemoveLifecycle2164=== PAUSE TestQueueFetchRemoveLifecycle2165=== RUN TestQueueConcurrentWriters2166=== PAUSE TestQueueConcurrentWriters2167=== RUN TestQueueRemoveLargeClosure2168=== PAUSE TestQueueRemoveLargeClosure2169=== RUN TestServerClientIntegration2170=== PAUSE TestServerClientIntegration2171=== RUN TestServerQueueError2172=== PAUSE TestServerQueueError2173=== RUN TestGetListenerSocketActivation2174 server_test.go:210: === RUN TestGetListenerSocketActivation2175 --- PASS: TestGetListenerSocketActivation (0.00s)2176 PASS2177 2178--- PASS: TestGetListenerSocketActivation (0.01s)2179=== RUN TestDrainIsolatesPoisonPath2180=== PAUSE TestDrainIsolatesPoisonPath2181=== RUN TestRunNotBlockedByPoisonHead2182=== PAUSE TestRunNotBlockedByPoisonHead2183=== RUN TestDrainGivesUpWhenServerDown2184=== PAUSE TestDrainGivesUpWhenServerDown2185=== RUN TestFailedPathPrunedByLaterClosure2186=== PAUSE TestFailedPathPrunedByLaterClosure2187=== RUN TestWorkerUploadsAndRemoves2188=== PAUSE TestWorkerUploadsAndRemoves2189=== RUN TestWorkerSkipsGCdPaths2190=== PAUSE TestWorkerSkipsGCdPaths2191=== RUN TestWorkerPrunesClosureDeps2192=== PAUSE TestWorkerPrunesClosureDeps2193=== RUN TestDrainTimeout2194=== PAUSE TestDrainTimeout2195=== CONT TestSendPathsEmpty2196--- PASS: TestSendPathsEmpty (0.00s)2197=== CONT TestServerQueueError2198=== CONT TestServerClientIntegration2199=== CONT TestQueueRemoveLargeClosure2200=== CONT TestQueueConcurrentWriters2201=== CONT TestQueueFetchRemoveLifecycle2202=== CONT TestQueueRetryMovesToBack2203=== CONT TestQueueFetchBatchLimit2204=== CONT TestQueueRemove2205=== CONT TestQueueDeduplication2206=== CONT TestQueueEnqueueAndFetch2207=== CONT TestWorkerPrunesClosureDeps22082026/09/10 03:42:22 ERROR Failed to queue paths error="permission denied" count=12209=== CONT TestDrainTimeout2210=== CONT TestWorkerSkipsGCdPaths2211=== CONT TestWorkerUploadsAndRemoves2212=== CONT TestFailedPathPrunedByLaterClosure2213=== CONT TestDrainIsolatesPoisonPath2214=== CONT TestRunNotBlockedByPoisonHead2215=== CONT TestDrainGivesUpWhenServerDown2216--- PASS: TestServerQueueError (0.00s)2217--- PASS: TestServerClientIntegration (0.00s)22182026/09/10 03:42:22 INFO Uploading batch count=122192026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=122202026/09/10 03:42:22 INFO Uploading batch count=222212026/09/10 03:42:22 INFO Upload queue status pending=322222026/09/10 03:42:22 INFO Uploading batch count=122232026/09/10 03:42:22 INFO Upload queue status pending=222242026/09/10 03:42:22 INFO Uploading batch count=222252026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=222262026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1511514236/002/a22272026/09/10 03:42:22 INFO Uploading batch count=122282026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=122292026/09/10 03:42:22 INFO Uploading batch count=422302026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=422312026/09/10 03:42:22 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1667177001/002/nonexistent22322026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1511514236/002/b22332026/09/10 03:42:22 INFO Upload queue status pending=222342026/09/10 03:42:22 INFO Uploading batch count=22235--- PASS: TestQueueEnqueueAndFetch (0.02s)22362026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath747831835/002/bbb2237--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22382026/09/10 03:42:22 INFO Uploading batch count=12239--- PASS: TestQueueRemove (0.02s)22402026/09/10 03:42:22 INFO Upload queue status pending=222412026/09/10 03:42:22 INFO Uploading batch count=122422026/09/10 03:42:22 INFO Uploading batch count=222432026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=222442026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1511514236/002/c22452026/09/10 03:42:22 INFO Uploading batch count=12246--- PASS: TestQueueDeduplication (0.02s)2247--- PASS: TestQueueFetchBatchLimit (0.02s)22482026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1511514236/002/d2249--- PASS: TestQueueRetryMovesToBack (0.02s)22502026/09/10 03:42:22 INFO Uploading batch count=222512026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=222522026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1511514236/002/e22532026/09/10 03:42:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1511514236/002/f22542026/09/10 03:42:22 INFO Uploading batch count=122552026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=122562026/09/10 03:42:22 ERROR Drain finished with paths left in queue remaining=1022572026/09/10 03:42:22 INFO Uploading batch count=122582026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=12259--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22602026/09/10 03:42:22 INFO Uploading batch count=122612026/09/10 03:42:22 ERROR Upload failed error="upload failed" count=122622026/09/10 03:42:22 ERROR Drain finished with paths left in queue remaining=12263--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2264--- PASS: TestDrainIsolatesPoisonPath (0.02s)2265--- PASS: TestWorkerUploadsAndRemoves (0.03s)2266--- PASS: TestWorkerSkipsGCdPaths (0.04s)2267--- PASS: TestWorkerPrunesClosureDeps (0.04s)2268--- PASS: TestQueueRemoveLargeClosure (0.10s)22692026/09/10 03:42:22 ERROR Upload failed error="context deadline exceeded" count=222702026/09/10 03:42:22 ERROR Drain finished with paths left in queue remaining=42271--- PASS: TestDrainTimeout (0.22s)2272--- PASS: TestQueueConcurrentWriters (0.27s)22732026/09/10 03:42:23 INFO Uploading batch count=122742026/09/10 03:42:23 INFO Uploading batch count=122752026/09/10 03:42:23 INFO Uploading batch count=122762026/09/10 03:42:23 ERROR Upload failed error="upload failed" count=122772026/09/10 03:42:23 INFO Uploading batch count=122782026/09/10 03:42:23 ERROR Upload failed error="upload failed" count=122792026/09/10 03:42:23 INFO Uploading batch count=122802026/09/10 03:42:23 ERROR Upload failed error="upload failed" count=122812026/09/10 03:42:23 INFO Uploading batch count=122822026/09/10 03:42:23 ERROR Upload failed error="upload failed" count=122832026/09/10 03:42:23 ERROR Drain finished with paths left in queue remaining=12284--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2285PASS

succeeded niks3-go-unit-tests checks.x86_64-linux.go-unit-tests · build #188 · raw

succeeded `niks3-go-unit-tests` `checks.x86_64-linux.go-unit-tests` · build #188 · raw