niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #257
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== 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 TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestShellSplit98=== CONT TestScriptTokenEmptyCommand99=== CONT TestSetClientTLSDoesNotMutateDefaultTransport100=== CONT TestStreamPushIsolatesFailures101=== CONT TestScriptTokenBadJSON102=== CONT TestScriptTokenEmptyToken103=== CONT TestScriptTokenCachesUntilRefresh1042026/09/23 09:40:55 ERROR Upload failed error="bad path" count=3105=== CONT TestScriptTokenNoExpiryRerunsEveryCall106=== CONT TestFileTokenEmpty107=== CONT TestFileTokenMissing108=== CONT TestFileTokenReadsAndCaches109=== CONT TestStaticToken110=== CONT TestSetClientTLSErrors111=== CONT TestStreamPushGivesUpOnDeadServer112=== CONT TestSetClientTLS113=== CONT TestUploadMultipart_SupersededByPeer114=== CONT TestClientSignaturesByStorePath115=== CONT TestStreamPushReportsSignatures116=== CONT TestStreamPushRequestLine117=== CONT TestPathInfoCACompatibility118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestResolveStorePath120=== CONT TestDumpPathWriterError121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1222026/09/23 09:40:55 ERROR Upload failed error="connection refused" count=201232026/09/23 09:40:55 ERROR Server seems unavailable, giving up on batch untried=17124=== CONT TestParsePathInfoJSONMultiplePaths125--- PASS: TestShellSplit (0.00s)126--- PASS: TestScriptTokenEmptyCommand (0.00s)127--- PASS: TestStaticToken (0.00s)128--- PASS: TestScriptTokenScriptFails (0.00s)129--- PASS: TestScriptTokenBadJSON (0.01s)130--- PASS: TestStreamPushIsolatesFailures (0.01s)131--- PASS: TestFileTokenEmpty (0.00s)132--- PASS: TestClientSignaturesByStorePath (0.00s)133=== CONT TestStreamPushBatchesUnderLoad134=== CONT TestEncodeNixBase32WithRealHash135--- PASS: TestFileTokenMissing (0.00s)136--- PASS: TestEncodeNixBase32WithRealHash (0.00s)137=== RUN TestPathInfoCACompatibility/null_ca_field138--- PASS: TestFileTokenReadsAndCaches (0.00s)139=== CONT TestFilterOversizedClosures140=== CONT TestPartSizeForNAR141=== CONT TestDumpPathSingleFile142=== RUN TestUploadMultipart_SupersededByPeer/exists1432026/09/23 09:40:55 WARN Rate limiter enabled after throttle name=server-test rate=5144=== CONT TestEncodeNixBase32145=== RUN TestEncodeNixBase32/test_string_hash146=== PAUSE TestEncodeNixBase32/test_string_hash147=== RUN TestEncodeNixBase32/empty_input148=== PAUSE TestEncodeNixBase32/empty_input1492026/09/23 09:40:55 WARN Rate limiter enabled after throttle name=server-test rate=5150=== PAUSE TestPathInfoCACompatibility/null_ca_field1512026/09/23 09:40:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35267152=== CONT TestParsePathInfoJSON153=== CONT TestDumpPathMatchesNix154=== CONT TestRateLimiterFeedback155=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths156=== RUN TestFilterOversizedClosures/no_limit_keeps_everything157=== RUN TestPartSizeForNAR/zero_stays_at_minimum158--- PASS: TestScriptTokenEmptyToken (0.01s)159=== PAUSE TestUploadMultipart_SupersededByPeer/exists1602026/09/23 09:40:55 ERROR Upload failed error=boom count=1161=== CONT TestUploadMultipart_PartsInParallel162=== RUN TestRateLimiterFeedback/429_enables_limiter163=== CONT TestPathInfoHashCompatibility164=== CONT TestCaseHackSuffix165=== RUN TestPathInfoCACompatibility/old_string_format_-_text166--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)167--- PASS: TestResolveStorePath (0.00s)168--- PASS: TestStreamPushReportsSignatures (0.00s)169=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths170=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum171=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything172=== PAUSE TestRateLimiterFeedback/429_enables_limiter173=== RUN TestUploadMultipart_SupersededByPeer/missing174=== RUN TestParsePathInfoJSON/Nix_format175=== PAUSE TestUploadMultipart_SupersededByPeer/missing176=== PAUSE TestParsePathInfoJSON/Nix_format177=== RUN TestParsePathInfoJSON/Lix_format178--- PASS: TestDoServerRequestAttachesToken (0.01s)179=== RUN TestPartSizeForNAR/small_stays_at_minimum180--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)181=== CONT TestGetStorePathHash182=== PAUSE TestPartSizeForNAR/small_stays_at_minimum183=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum184=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum185=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts186=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts187=== RUN TestPartSizeForNAR/1_TiB188=== PAUSE TestPartSizeForNAR/1_TiB189=== RUN TestGetStorePathHash/valid_store_path190=== CONT TestStreamPushReportsEveryPath1912026/09/23 09:40:55 ERROR Upload failed error=boom count=1192=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1932026/09/23 09:40:55 WARN Rate limiter backed off name=server-test rate=5194=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped195=== RUN TestFilterOversizedClosures/all_closures_skipped1962026/09/23 09:40:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35267197=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text198=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== PAUSE TestFilterOversizedClosures/all_closures_skipped200--- PASS: TestStreamPushReportsEveryPath (0.03s)201=== CONT TestShellSplitErrors202=== RUN TestRateLimiterFeedback/503_enables_limiter203=== PAUSE TestParsePathInfoJSON/Lix_format204=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)205=== RUN TestSetClientTLSErrors/missing_cert_file206=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths207=== RUN TestPartSizeForNAR/5_TiB_S3_max_object208=== PAUSE TestGetStorePathHash/valid_store_path209=== RUN TestSetClientTLS/rejects_connection_without_client_cert210=== CONT TestConvertHashToNix32211=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive212=== RUN TestGetStorePathHash/basename_without_hyphen_should_error213=== RUN TestConvertHashToNix32/SRI_format_to_Nix32214=== RUN TestPathInfoCACompatibility/new_structured_format_-_text215=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error216=== CONT TestRegisterUploadedObjectReusesConnections217=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error220=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error221=== CONT TestUploadMultipart_SupersededByPeer/exists222=== CONT TestUploadMultipart_SupersededByPeer/missing223=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)224--- PASS: TestShellSplitErrors (0.00s)225--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)226=== CONT TestEncodeNixBase32/empty_input227=== CONT TestFilterOversizedClosures/no_limit_keeps_everything228=== RUN TestParsePathInfoJSON/empty_input229=== PAUSE TestParsePathInfoJSON/empty_input230=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2312026/09/23 09:40:55 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=2000232=== CONT TestGetStorePathHash/valid_store_path233=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error234=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error235=== RUN TestParsePathInfoJSON/whitespace_only236=== PAUSE TestParsePathInfoJSON/whitespace_only237=== RUN TestParsePathInfoJSON/invalid_JSON238=== CONT TestGetStorePathHash/basename_without_hyphen_should_error239=== PAUSE TestParsePathInfoJSON/invalid_JSON240=== CONT TestParsePathInfoJSON/Nix_format241=== PAUSE TestSetClientTLSErrors/missing_cert_file242=== RUN TestSetClientTLSErrors/missing_key_file243=== PAUSE TestSetClientTLSErrors/missing_key_file244=== RUN TestSetClientTLSErrors/missing_ca_file245=== PAUSE TestSetClientTLSErrors/missing_ca_file246=== RUN TestSetClientTLSErrors/invalid_ca_file247=== PAUSE TestSetClientTLSErrors/invalid_ca_file248=== CONT TestEncodeNixBase32/test_string_hash249=== CONT TestSetClientTLSErrors/missing_cert_file250=== CONT TestParsePathInfoJSON/Lix_format251=== CONT TestParsePathInfoJSON/empty_input252=== CONT TestSetClientTLSErrors/invalid_ca_file253=== CONT TestSetClientTLSErrors/missing_key_file254=== CONT TestSetClientTLSErrors/missing_ca_file255=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert256=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32257=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text258=== PAUSE TestRateLimiterFeedback/503_enables_limiter259=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon260--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)261=== CONT TestFilterOversizedClosures/all_closures_skipped262=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths263=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object264=== CONT TestParsePathInfoJSON/whitespace_only265=== CONT TestParsePathInfoJSON/invalid_JSON266=== RUN TestConvertHashToNix32/already_Nix32_format267=== PAUSE TestConvertHashToNix32/already_Nix32_format268=== RUN TestConvertHashToNix32/invalid_format269=== PAUSE TestConvertHashToNix32/invalid_format270=== CONT TestConvertHashToNix32/SRI_format_to_Nix32271=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths272=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA273=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon274=== RUN TestPartSizeForNAR/capped_at_5_GiB2752026/09/23 09:40:55 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=50276=== PAUSE TestPartSizeForNAR/capped_at_5_GiB277=== CONT TestPartSizeForNAR/zero_stays_at_minimum278=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths279=== CONT TestPartSizeForNAR/1_TiB280=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum281=== CONT TestConvertHashToNix32/already_Nix32_format282=== CONT TestPartSizeForNAR/capped_at_5_GiB283=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI284=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI285=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512286--- PASS: TestGetStorePathHash (0.03s)287 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)288 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)289 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)290 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)291--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)292=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method293=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method294=== CONT TestPathInfoCACompatibility/null_ca_field295=== CONT TestPathInfoCACompatibility/new_structured_format_-_text296=== CONT TestPathInfoCACompatibility/old_string_format_-_text297=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298=== CONT TestPartSizeForNAR/5_TiB_S3_max_object299=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts300=== CONT TestConvertHashToNix32/invalid_format301=== CONT TestPartSizeForNAR/small_stays_at_minimum302=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA303=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== RUN TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon306=== PAUSE TestSetClientTLS/preserves_debug_logging_transport307=== CONT TestSetClientTLS/rejects_connection_without_client_cert308=== CONT TestSetClientTLS/preserves_debug_logging_transport309=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter310=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter311=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method312=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)313=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI314=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512315--- PASS: TestDumpPathSingleFile (0.04s)316=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA317=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter318=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter319=== CONT TestRateLimiterFeedback/429_enables_limiter320--- PASS: TestEncodeNixBase32 (0.00s)321 --- PASS: TestEncodeNixBase32/empty_input (0.00s)322 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)323--- PASS: TestConvertHashToNix32 (0.00s)324 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)325 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)326 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)327=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter328--- PASS: TestPartSizeForNAR (0.04s)329 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)330 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)331 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)332 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)333 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)334 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)335 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)336--- PASS: TestPathInfoCACompatibility (0.04s)337 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)338 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)339 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)341 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)342--- PASS: TestSetClientTLSErrors (0.04s)343 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)345 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)346 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3472026/09/23 09:40:55 WARN Rate limiter enabled after throttle name=server-test rate=5348--- PASS: TestParsePathInfoJSON (0.03s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)351 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)352 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)353 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)3542026/09/23 09:40:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39897355--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)356 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)357 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)358--- PASS: TestFilterOversizedClosures (0.03s)359 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)360 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)361 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)362--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)363 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)364 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)365--- PASS: TestPathInfoHashCompatibility (0.03s)366 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)368 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)369 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)370=== CONT TestRateLimiterFeedback/503_enables_limiter3712026/09/23 09:40:55 WARN Rate limiter backed off name=server-test rate=5372=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3732026/09/23 09:40:55 WARN Rate limiter enabled after throttle name=server-test rate=53742026/09/23 09:40:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:446473752026/09/23 09:40:55 WARN Rate limiter backed off name=server-test rate=5376--- PASS: TestRateLimiterFeedback (0.04s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)380 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3812026/09/23 09:40:55 http: TLS handshake error from 127.0.0.1:53850: remote error: tls: bad certificate382--- PASS: TestStreamPushRequestLine (0.06s)383--- PASS: TestSetClientTLS (0.04s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestCaseHackSuffix (0.06s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)389--- PASS: TestDumpPathWriterError (0.09s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.13s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1048610488/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1048610488/data -l logfile start422423/build/postgres1048610488:5432 - no response4242026-09-23 09:40:57.157 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 09:40:57.158 UTC [128] LOG: listening on Unix socket "/build/postgres1048610488/.s.PGSQL.5432"4262026-09-23 09:40:57.162 UTC [135] LOG: database system was shut down at 2026-09-23 09:40:56 UTC4272026-09-23 09:40:57.167 UTC [128] LOG: database system is ready to accept connections428/build/postgres1048610488:5432 - accepting connections429{"timestamp":"2026-09-23T09:40:57.466630853Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9bcbef30-4cfa-4489-8849-7143acf13690","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(393)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestResolveDBConnectionString463=== PAUSE TestResolveDBConnectionString464=== RUN TestLeadElectsOneAndHandsOver465=== PAUSE TestLeadElectsOneAndHandsOver466=== RUN TestLeadIncumbentWinsAfterRestart4672026-09-23 09:40:57.658 UTC [564] ERROR: relation "goose_db_version" does not exist at character 364682026-09-23 09:40:57.658 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/23 09:40:57 OK 20241026095416_initial_model.sql (7.69ms)4702026/09/23 09:40:57 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)4712026/09/23 09:40:57 OK 20251218171726_add_pins.sql (2ms)4722026/09/23 09:40:57 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)4732026/09/23 09:40:57 OK 20260905000000_add_claims.sql (2.12ms)4742026/09/23 09:40:57 OK 20260920000000_drop_claims.sql (1.42ms)4752026/09/23 09:40:57 goose: successfully migrated database to version: 202609200000004762026/09/23 09:40:57 OK 1_commit_pending_closure.sql (1.51ms)4772026/09/23 09:40:57 OK 2_object_stats_trigger.sql (759.46µs)4782026/09/23 09:40:57 goose: up to current file version: 24792026/09/23 09:40:57 INFO lead: acquired remote=192.0.2.1:12344802026/09/23 09:40:58 INFO lead: released remote=192.0.2.1:12344812026/09/23 09:40:58 INFO lead: acquired remote=192.0.2.1:12344822026/09/23 09:40:58 INFO lead: released remote=192.0.2.1:1234483--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)484=== RUN TestLeadEndsOnShutdown485=== PAUSE TestLeadEndsOnShutdown486=== RUN TestGCAdvisoryLockBlocksConcurrentRun4872026-09-23 09:40:58.428 UTC [574] ERROR: relation "goose_db_version" does not exist at character 364882026-09-23 09:40:58.428 UTC [574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4892026/09/23 09:40:58 OK 20241026095416_initial_model.sql (6.72ms)4902026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)4912026/09/23 09:40:58 OK 20251218171726_add_pins.sql (2.51ms)4922026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (2.03ms)4932026/09/23 09:40:58 OK 20260905000000_add_claims.sql (2.19ms)4942026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (1.54ms)4952026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000004962026/09/23 09:40:58 OK 1_commit_pending_closure.sql (1.49ms)4972026/09/23 09:40:58 OK 2_object_stats_trigger.sql (833.33µs)4982026/09/23 09:40:58 goose: up to current file version: 2499--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)500=== RUN TestGCBugBareHashReferences501=== PAUSE TestGCBugBareHashReferences502=== RUN TestGCMetrics503=== PAUSE TestGCMetrics504=== RUN TestGCTaskStore_StartNew505=== PAUSE TestGCTaskStore_StartNew506=== RUN TestGCTaskStore_DeduplicateSameParams507=== PAUSE TestGCTaskStore_DeduplicateSameParams508=== RUN TestGCTaskStore_ConflictDifferentParams509=== PAUSE TestGCTaskStore_ConflictDifferentParams510=== RUN TestGCTaskStore_GetEmpty511=== PAUSE TestGCTaskStore_GetEmpty512=== RUN TestGCTaskStore_GetReturnsLatest513=== PAUSE TestGCTaskStore_GetReturnsLatest514=== RUN TestGCTaskStore_CompletedAllowsNewTask515=== PAUSE TestGCTaskStore_CompletedAllowsNewTask516=== RUN TestGCTaskStore_PhaseUpdates517=== PAUSE TestGCTaskStore_PhaseUpdates518=== RUN TestGCTaskStore_Fail519=== PAUSE TestGCTaskStore_Fail520=== RUN TestGracefulShutdownDrainsInflight521=== PAUSE TestGracefulShutdownDrainsInflight522=== RUN TestService_healthCheckHandler523=== PAUSE TestService_healthCheckHandler524=== RUN TestService_readinessHandler525=== PAUSE TestService_readinessHandler526=== RUN TestGenerateLandingPage527=== PAUSE TestGenerateLandingPage528=== RUN TestCacheConfigHandlerMaxNarSize529=== PAUSE TestCacheConfigHandlerMaxNarSize530=== RUN TestCreatePendingClosureRejectsOversizedNAR531=== PAUSE TestCreatePendingClosureRejectsOversizedNAR532=== RUN TestNARDeduplicationMetadataUploadBug533=== PAUSE TestNARDeduplicationMetadataUploadBug534=== RUN TestMetricsInventory535=== PAUSE TestMetricsInventory536=== RUN TestService_NativeMTLS537=== PAUSE TestService_NativeMTLS538=== RUN TestServerTLSConfig539=== PAUSE TestServerTLSConfig540=== RUN TestMultipartCleanup541=== PAUSE TestMultipartCleanup542=== RUN TestObjectStatsTrigger543=== PAUSE TestObjectStatsTrigger544=== RUN TestOrphanedObjectsGC545=== PAUSE TestOrphanedObjectsGC546=== RUN TestOrphanedObjectsGCStressTest547=== PAUSE TestOrphanedObjectsGCStressTest548=== RUN TestResurrectedObjectNotDeleted549=== PAUSE TestResurrectedObjectNotDeleted550=== RUN TestCreatePin_ReservedPins551=== PAUSE TestCreatePin_ReservedPins552=== RUN TestParseSingleRange553=== PAUSE TestParseSingleRange554=== RUN TestProxyHeadersOnlyTrustedOnSocket555=== PAUSE TestProxyHeadersOnlyTrustedOnSocket556=== RUN TestIsValidCachePath557=== PAUSE TestIsValidCachePath558=== RUN TestReadProxyNarinfo559=== PAUSE TestReadProxyNarinfo560=== RUN TestReadProxyNarinfoAlreadyDecompressed561=== PAUSE TestReadProxyNarinfoAlreadyDecompressed562=== RUN TestReadProxyNarStreaming563=== PAUSE TestReadProxyNarStreaming564=== RUN TestReadProxy404565=== PAUSE TestReadProxy404566=== RUN TestReadProxyInvalidPath567=== PAUSE TestReadProxyInvalidPath568=== RUN TestReadProxyHead569=== PAUSE TestReadProxyHead570=== RUN TestReadProxyConditionalGet571=== PAUSE TestReadProxyConditionalGet572=== RUN TestReadProxyRootRedirectsToIndexHTML573=== PAUSE TestReadProxyRootRedirectsToIndexHTML574=== RUN TestReadProxyDisabled575=== PAUSE TestReadProxyDisabled576=== RUN TestReadRedirectNar577=== PAUSE TestReadRedirectNar578=== RUN TestReadRedirectKeepsNarinfoProxied579=== PAUSE TestReadRedirectKeepsNarinfoProxied580=== RUN TestReadProxyRangeRequest581=== PAUSE TestReadProxyRangeRequest582=== RUN TestReadRedirectUsesPublicS3URL583=== PAUSE TestReadRedirectUsesPublicS3URL584=== RUN TestRedundantMultipartUpload585=== PAUSE TestRedundantMultipartUpload586=== RUN TestCompleteMultipartUpload_ErrorButObjectExists587=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists588=== RUN TestCompletedNarNotReofferedAcrossClosures589=== PAUSE TestCompletedNarNotReofferedAcrossClosures590=== RUN TestPresignedUploadRegisteredBeforeCommit591=== PAUSE TestPresignedUploadRegisteredBeforeCommit592=== RUN TestService_Rustfstest593=== PAUSE TestService_Rustfstest594=== RUN TestParseSize595=== PAUSE TestParseSize596=== RUN TestSkippedUploadsHandler597=== PAUSE TestSkippedUploadsHandler598=== RUN TestSystemdListenerNotActivated599--- PASS: TestSystemdListenerNotActivated (0.00s)600=== RUN TestWatchdogBeatsWhenHealthy601--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)602=== RUN TestWatchdogSkipsWhenUnhealthy6032026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6042026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6052026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6062026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6072026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6082026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6092026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6102026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6112026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6122026/09/23 09:40:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"613--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)614=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle615=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle616=== RUN TestProxyWriteTimeout617=== PAUSE TestProxyWriteTimeout618=== RUN TestIsValidUploadKey619=== PAUSE TestIsValidUploadKey620=== RUN TestUploadHandlersRejectInvalidKeys621=== PAUSE TestUploadHandlersRejectInvalidKeys622=== RUN TestUploadHandlersRejectOversizedBody623=== PAUSE TestUploadHandlersRejectOversizedBody624=== RUN TestService_cleanupPendingClosuresHandler625=== PAUSE TestService_cleanupPendingClosuresHandler626=== RUN TestService_createPendingClosureHandler627=== PAUSE TestService_createPendingClosureHandler628=== RUN TestService_verifyS3Integrity629=== PAUSE TestService_verifyS3Integrity630=== RUN TestCompleteMultipartUnregistered631=== PAUSE TestCompleteMultipartUnregistered632=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT633=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT634=== CONT TestService_AuthMiddleware635=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT636=== CONT TestCompleteMultipartUpload_ErrorButObjectExists637=== CONT TestCompleteMultipartUnregistered638=== CONT TestService_verifyS3Integrity639=== CONT TestService_createPendingClosureHandler640=== CONT TestService_cleanupPendingClosuresHandler641=== CONT TestUploadHandlersRejectOversizedBody642=== CONT TestUploadHandlersRejectInvalidKeys643=== CONT TestIsValidUploadKey644=== RUN TestIsValidUploadKey/narinfo645=== PAUSE TestIsValidUploadKey/narinfo646=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info647=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info648=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal649=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal650=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key651=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key652=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key653=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key654=== CONT TestProxyWriteTimeout655=== RUN TestProxyWriteTimeout/narinfo656=== PAUSE TestProxyWriteTimeout/narinfo657=== RUN TestProxyWriteTimeout/1_GiB_nar658=== RUN TestIsValidUploadKey/nar_zst659=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle660=== CONT TestSkippedUploadsHandler661=== CONT TestParseSize662=== CONT TestService_Rustfstest663=== CONT TestPresignedUploadRegisteredBeforeCommit664=== CONT TestCompletedNarNotReofferedAcrossClosures665=== CONT TestGCTaskStore_GetEmpty666=== CONT TestProxyHeadersOnlyTrustedOnSocket667=== CONT TestParseSingleRange668=== CONT TestCreatePin_ReservedPins669=== CONT TestResurrectedObjectNotDeleted670=== CONT TestOrphanedObjectsGCStressTest671=== CONT TestIsValidCachePath672=== CONT TestOrphanedObjectsGC673=== PAUSE TestIsValidUploadKey/nar_zst674=== PAUSE TestProxyWriteTimeout/1_GiB_nar675--- PASS: TestGCTaskStore_GetEmpty (0.00s)676=== RUN TestProxyWriteTimeout/10_GiB_nar677=== RUN TestIsValidUploadKey/nar_xz6782026/09/23 09:40:58 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000679=== RUN TestIsValidCachePath/narinfo680=== PAUSE TestIsValidCachePath/narinfo681=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars682=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars683=== RUN TestIsValidCachePath/nar_zst684=== PAUSE TestIsValidCachePath/nar_zst685=== RUN TestIsValidCachePath/nar_xz686=== PAUSE TestIsValidCachePath/nar_xz687=== RUN TestIsValidCachePath/nar_bz2688=== PAUSE TestIsValidCachePath/nar_bz2689=== CONT TestObjectStatsTrigger690--- PASS: TestParseSize (0.00s)691=== CONT TestMultipartCleanup692=== RUN TestParseSingleRange/none693=== PAUSE TestParseSingleRange/none694=== PAUSE TestProxyWriteTimeout/10_GiB_nar695=== PAUSE TestIsValidUploadKey/nar_xz696=== RUN TestIsValidCachePath/nar_uncompressed697=== RUN TestParseSingleRange/unknown_unit698=== PAUSE TestParseSingleRange/unknown_unit699=== RUN TestProxyWriteTimeout/unknown_size700=== PAUSE TestProxyWriteTimeout/unknown_size701=== RUN TestIsValidUploadKey/nar_plain702=== PAUSE TestIsValidUploadKey/nar_plain703=== RUN TestIsValidUploadKey/listing704=== PAUSE TestIsValidUploadKey/listing705=== RUN TestIsValidUploadKey/build_log706=== PAUSE TestIsValidUploadKey/build_log707=== RUN TestIsValidUploadKey/build_log_home-manager_file708=== PAUSE TestIsValidUploadKey/build_log_home-manager_file709=== RUN TestIsValidUploadKey/build_log_plus_in_name710=== PAUSE TestIsValidUploadKey/build_log_plus_in_name711=== PAUSE TestIsValidCachePath/nar_uncompressed712=== RUN TestParseSingleRange/multi-range_ignored713=== PAUSE TestParseSingleRange/multi-range_ignored714=== CONT TestServerTLSConfig715=== RUN TestIsValidUploadKey/build_log_question_mark716=== PAUSE TestIsValidUploadKey/build_log_question_mark717=== RUN TestIsValidCachePath/ls718=== RUN TestParseSingleRange/malformed_no_dash719=== PAUSE TestParseSingleRange/malformed_no_dash720=== RUN TestServerTLSConfig/no_client_CA721=== PAUSE TestServerTLSConfig/no_client_CA722=== RUN TestServerTLSConfig/missing_CA_file723=== RUN TestIsValidUploadKey/build_log_equals724=== PAUSE TestIsValidUploadKey/build_log_equals725=== PAUSE TestIsValidCachePath/ls726=== RUN TestIsValidCachePath/log727=== PAUSE TestIsValidCachePath/log728=== RUN TestIsValidCachePath/realisation729=== PAUSE TestIsValidCachePath/realisation730=== RUN TestParseSingleRange/malformed_both_empty731=== PAUSE TestParseSingleRange/malformed_both_empty732=== PAUSE TestServerTLSConfig/missing_CA_file733=== RUN TestIsValidUploadKey/realisation734=== RUN TestServerTLSConfig/not_a_PEM_file735=== PAUSE TestIsValidUploadKey/realisation736=== RUN TestIsValidUploadKey/realisation_plus_in_output737=== PAUSE TestIsValidUploadKey/realisation_plus_in_output738=== RUN TestIsValidUploadKey/nix-cache-info739=== PAUSE TestIsValidUploadKey/nix-cache-info740=== RUN TestIsValidUploadKey/index.html741=== PAUSE TestIsValidUploadKey/index.html742=== RUN TestIsValidUploadKey/narinfo_key,_nar_type743--- PASS: TestSkippedUploadsHandler (0.07s)744=== CONT TestService_NativeMTLS745=== RUN TestParseSingleRange/malformed_end_before_start746=== PAUSE TestParseSingleRange/malformed_end_before_start747=== RUN TestIsValidCachePath/nix-cache-info748=== PAUSE TestServerTLSConfig/not_a_PEM_file749=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type750=== RUN TestIsValidUploadKey/nar_key,_narinfo_type751=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type752=== RUN TestIsValidUploadKey/listing_key,_narinfo_type753=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type754=== RUN TestIsValidUploadKey/traversal755=== PAUSE TestIsValidUploadKey/traversal756=== RUN TestIsValidUploadKey/traversal_nar757=== PAUSE TestIsValidUploadKey/traversal_nar758=== RUN TestIsValidUploadKey/absolute759=== PAUSE TestIsValidUploadKey/absolute760=== RUN TestIsValidUploadKey/empty_key761=== PAUSE TestIsValidUploadKey/empty_key762=== RUN TestIsValidUploadKey/unknown_type763=== PAUSE TestIsValidUploadKey/unknown_type764=== RUN TestParseSingleRange/closed765=== PAUSE TestParseSingleRange/closed766=== RUN TestParseSingleRange/open-ended767=== PAUSE TestParseSingleRange/open-ended768=== PAUSE TestIsValidCachePath/nix-cache-info769=== CONT TestMetricsInventory770=== CONT TestNARDeduplicationMetadataUploadBug771=== RUN TestParseSingleRange/end_clamped_to_size772=== PAUSE TestParseSingleRange/end_clamped_to_size773=== RUN TestParseSingleRange/suffix774=== PAUSE TestParseSingleRange/suffix775=== RUN TestParseSingleRange/suffix_exceeds_size776=== PAUSE TestParseSingleRange/suffix_exceeds_size777=== RUN TestParseSingleRange/single_byte778=== PAUSE TestParseSingleRange/single_byte779=== RUN TestIsValidCachePath/index.html780=== PAUSE TestIsValidCachePath/index.html781=== RUN TestIsValidCachePath/traversal_parent782=== RUN TestParseSingleRange/start_past_EOF783=== PAUSE TestParseSingleRange/start_past_EOF784=== PAUSE TestIsValidCachePath/traversal_parent785=== RUN TestParseSingleRange/start_far_past_EOF786=== PAUSE TestParseSingleRange/start_far_past_EOF787=== RUN TestIsValidCachePath/traversal_in_middle788=== PAUSE TestIsValidCachePath/traversal_in_middle789=== RUN TestIsValidCachePath/invalid_char_e790=== PAUSE TestIsValidCachePath/invalid_char_e791=== RUN TestIsValidCachePath/invalid_char_u792=== PAUSE TestIsValidCachePath/invalid_char_u793=== RUN TestIsValidCachePath/random_path794=== PAUSE TestIsValidCachePath/random_path795=== RUN TestIsValidCachePath/empty796=== PAUSE TestIsValidCachePath/empty797=== RUN TestIsValidCachePath/leading_slash798=== PAUSE TestIsValidCachePath/leading_slash799=== RUN TestIsValidCachePath/wrong_extension800=== PAUSE TestIsValidCachePath/wrong_extension801=== CONT TestCreatePendingClosureRejectsOversizedNAR802=== RUN TestIsValidCachePath/short_hash803=== PAUSE TestIsValidCachePath/short_hash804=== CONT TestCacheConfigHandlerMaxNarSize805--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)8062026/09/23 09:40:58 INFO Received uploads request method=POST path=/api/pending_closures807=== CONT TestGenerateLandingPage808--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)809=== CONT TestService_readinessHandler810--- PASS: TestGenerateLandingPage (0.00s)811=== CONT TestService_healthCheckHandler8122026-09-23 09:40:58.859 UTC [637] ERROR: relation "goose_db_version" does not exist at character 368132026-09-23 09:40:58.859 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-09-23 09:40:58.874 UTC [639] ERROR: relation "goose_db_version" does not exist at character 368152026-09-23 09:40:58.874 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026-09-23 09:40:58.875 UTC [638] ERROR: relation "goose_db_version" does not exist at character 368172026-09-23 09:40:58.875 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC818=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts819=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts820=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure821=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure822=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart823=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart824=== CONT TestGracefulShutdownDrainsInflight8252026/09/23 09:40:58 INFO Starting HTTP server address=127.0.0.1:410518262026/09/23 09:40:58 INFO Shutdown signal received, draining in-flight requests timeout=10s8272026-09-23 09:40:58.902 UTC [640] ERROR: relation "goose_db_version" does not exist at character 368282026-09-23 09:40:58.902 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026-09-23 09:40:58.909 UTC [641] ERROR: relation "goose_db_version" does not exist at character 368302026-09-23 09:40:58.909 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-23 09:40:58.914 UTC [642] ERROR: relation "goose_db_version" does not exist at character 368322026-09-23 09:40:58.914 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/09/23 09:40:58 OK 20241026095416_initial_model.sql (51.37ms)8342026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)8352026-09-23 09:40:58.930 UTC [646] ERROR: relation "goose_db_version" does not exist at character 368362026-09-23 09:40:58.930 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/09/23 09:40:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39665/oidc8382026/09/23 09:40:58 OK 20241026095416_initial_model.sql (33.27ms)8392026/09/23 09:40:58 OK 20241026095416_initial_model.sql (35.46ms)8402026/09/23 09:40:58 OK 20251218171726_add_pins.sql (12.43ms)8412026/09/23 09:40:58 OK 20241026095416_initial_model.sql (25.7ms)8422026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)8432026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)8442026/09/23 09:40:58 OK 20241026095416_initial_model.sql (21.73ms)8452026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)8462026-09-23 09:40:58.946 UTC [648] ERROR: relation "goose_db_version" does not exist at character 368472026-09-23 09:40:58.946 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026-09-23 09:40:58.946 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368492026-09-23 09:40:58.946 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/09/23 09:40:58 OK 20241026095416_initial_model.sql (21.31ms)8512026/09/23 09:40:58 OK 20251218171726_add_pins.sql (5.6ms)8522026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)8532026/09/23 09:40:58 OK 20251218171726_add_pins.sql (4.18ms)8542026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (7.71ms)8552026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)8562026/09/23 09:40:58 OK 20251218171726_add_pins.sql (5ms)857--- PASS: TestGracefulShutdownDrainsInflight (0.07s)858=== CONT TestGCTaskStore_Fail859--- PASS: TestGCTaskStore_Fail (0.00s)860=== CONT TestGCTaskStore_PhaseUpdates861--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)862=== CONT TestGCTaskStore_CompletedAllowsNewTask863--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)864=== CONT TestGCTaskStore_GetReturnsLatest865--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)866=== CONT TestClientMultipleUploads8672026/09/23 09:40:58 OK 20251218171726_add_pins.sql (7.08ms)8682026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (7.5ms)8692026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (7.03ms)8702026/09/23 09:40:58 OK 20251218171726_add_pins.sql (6.19ms)8712026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (6.52ms)8722026/09/23 09:40:58 OK 20260905000000_add_claims.sql (8.71ms)8732026/09/23 09:40:58 OK 20241026095416_initial_model.sql (15.03ms)8742026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (7.37ms)8752026/09/23 09:40:58 OK 20260905000000_add_claims.sql (5.75ms)8762026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (7.06ms)8772026/09/23 09:40:58 OK 20260905000000_add_claims.sql (7.22ms)8782026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)8792026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (6.61ms)8802026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000008812026/09/23 09:40:58 OK 20260905000000_add_claims.sql (8.76ms)8822026-09-23 09:40:58.965 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368832026-09-23 09:40:58.965 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8842026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (4.92ms)8852026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000008862026-09-23 09:40:58.971 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368872026-09-23 09:40:58.971 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8882026/09/23 09:40:58 OK 1_commit_pending_closure.sql (12.87ms)8892026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (13.05ms)8902026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000008912026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (14.61ms)8922026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000008932026/09/23 09:40:58 OK 1_commit_pending_closure.sql (11.64ms)8942026/09/23 09:40:58 OK 20260905000000_add_claims.sql (16.88ms)8952026/09/23 09:40:58 OK 20260905000000_add_claims.sql (17.18ms)8962026/09/23 09:40:58 OK 20241026095416_initial_model.sql (26.14ms)8972026/09/23 09:40:58 OK 20251218171726_add_pins.sql (16.64ms)8982026/09/23 09:40:58 OK 2_object_stats_trigger.sql (3.77ms)8992026/09/23 09:40:58 goose: up to current file version: 29002026/09/23 09:40:58 OK 1_commit_pending_closure.sql (3.05ms)9012026/09/23 09:40:58 OK 2_object_stats_trigger.sql (3.6ms)9022026/09/23 09:40:58 goose: up to current file version: 29032026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (3.12ms)9042026/09/23 09:40:58 OK 1_commit_pending_closure.sql (5.59ms)9052026/09/23 09:40:58 OK 2_object_stats_trigger.sql (4.58ms)9062026/09/23 09:40:58 goose: up to current file version: 29072026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (6.34ms)9082026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000009092026/09/23 09:40:58 OK 20260920000000_drop_claims.sql (6.48ms)9102026/09/23 09:40:58 goose: successfully migrated database to version: 202609200000009112026/09/23 09:40:58 OK 2_object_stats_trigger.sql (4.33ms)9122026/09/23 09:40:58 goose: up to current file version: 29132026/09/23 09:40:58 OK 20260628120000_add_object_size_and_stats.sql (7.78ms)9142026/09/23 09:40:58 OK 20241026095416_initial_model.sql (32.56ms)9152026/09/23 09:40:58 OK 20251218171726_add_pins.sql (6.86ms)9162026/09/23 09:40:58 OK 1_commit_pending_closure.sql (5.8ms)9172026/09/23 09:40:58 OK 20251210153512_drop_unused_gin_index.sql (4.22ms)9182026/09/23 09:40:58 OK 1_commit_pending_closure.sql (5.69ms)9192026/09/23 09:40:58 OK 20260905000000_add_claims.sql (6.62ms)9202026/09/23 09:40:58 OK 20241026095416_initial_model.sql (12.72ms)9212026/09/23 09:40:58 OK 2_object_stats_trigger.sql (4.98ms)9222026/09/23 09:40:58 goose: up to current file version: 29232026/09/23 09:40:59 OK 2_object_stats_trigger.sql (6.18ms)9242026/09/23 09:40:59 goose: up to current file version: 29252026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (8.19ms)9262026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (4.48ms)9272026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000009282026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (5.05ms)9292026/09/23 09:40:59 OK 20251218171726_add_pins.sql (8.98ms)9302026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.08ms)9312026-09-23 09:40:59.005 UTC [655] ERROR: relation "goose_db_version" does not exist at character 369322026-09-23 09:40:59.005 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9332026-09-23 09:40:59.005 UTC [656] ERROR: relation "goose_db_version" does not exist at character 369342026-09-23 09:40:59.005 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026/09/23 09:40:59 OK 20260905000000_add_claims.sql (5.19ms)9362026/09/23 09:40:59 OK 2_object_stats_trigger.sql (3.04ms)9372026/09/23 09:40:59 goose: up to current file version: 29382026/09/23 09:40:59 OK 20251218171726_add_pins.sql (6.96ms)9392026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.6ms)9402026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000009412026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures9422026-09-23 09:40:59.013 UTC [657] ERROR: relation "goose_db_version" does not exist at character 369432026-09-23 09:40:59.013 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (13.89ms)9452026/09/23 09:40:59 OK 1_commit_pending_closure.sql (10.05ms)9462026/09/23 09:40:59 OK 20241026095416_initial_model.sql (26.71ms)9472026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (10.97ms)9482026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.45ms)9492026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.84ms)9502026/09/23 09:40:59 goose: up to current file version: 29512026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)9522026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.36ms)9532026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000009542026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.3ms)9552026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.43ms)9562026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000009572026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.97ms)9582026-09-23 09:40:59.026 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369592026-09-23 09:40:59.026 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9602026-09-23 09:40:59.027 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369612026-09-23 09:40:59.027 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9622026/09/23 09:40:59 OK 20251218171726_add_pins.sql (5.19ms)9632026/09/23 09:40:59 OK 2_object_stats_trigger.sql (2.3ms)9642026/09/23 09:40:59 goose: up to current file version: 29652026-09-23 09:40:59.029 UTC [662] ERROR: relation "goose_db_version" does not exist at character 369662026-09-23 09:40:59.029 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.62ms)9682026-09-23 09:40:59.030 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369692026-09-23 09:40:59.030 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9702026/09/23 09:40:59 OK 20241026095416_initial_model.sql (11.2ms)9712026-09-23 09:40:59.031 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369722026-09-23 09:40:59.031 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9732026/09/23 09:40:59 OK 2_object_stats_trigger.sql (2.93ms)9742026/09/23 09:40:59 goose: up to current file version: 29752026/09/23 09:40:59 OK 20241026095416_initial_model.sql (12.51ms)9762026-09-23 09:40:59.033 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369772026-09-23 09:40:59.033 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9782026/09/23 09:40:59 OK 20241026095416_initial_model.sql (11.76ms)9792026-09-23 09:40:59.033 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369802026-09-23 09:40:59.033 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9812026/09/23 09:40:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"982--- PASS: TestService_AuthMiddleware (0.32s)9832026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (5.45ms)984=== CONT TestGCTaskStore_ConflictDifferentParams985--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)986=== CONT TestGCTaskStore_DeduplicateSameParams987--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)988=== CONT TestGCTaskStore_StartNew9892026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)990--- PASS: TestGCTaskStore_StartNew (0.00s)991=== CONT TestGCMetrics9922026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)9932026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)9942026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.88ms)9952026/09/23 09:40:59 OK 20260905000000_add_claims.sql (4.26ms)9962026/09/23 09:40:59 OK 20251218171726_add_pins.sql (4.01ms)9972026/09/23 09:40:59 OK 20251218171726_add_pins.sql (4.24ms)9982026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.91ms)9992026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010002026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)10012026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.41ms)10022026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)10032026/09/23 09:40:59 OK 2_object_stats_trigger.sql (2.11ms)10042026/09/23 09:40:59 goose: up to current file version: 210052026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (5.37ms)10062026/09/23 09:40:59 OK 20260905000000_add_claims.sql (4.04ms)10072026/09/23 09:40:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/09/23 09:40:59 OK 20241026095416_initial_model.sql (11.94ms)10092026/09/23 09:40:59 OK 20241026095416_initial_model.sql (12.61ms)10102026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)10112026/09/23 09:40:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTNmYThjNDEtNjU1ZS00ZDI4LWI3OTAtNjkxYjY1MTgzZDIzLjgyMDBhYmUwLWI5ZjQtNDkzYS1hMmY3LWNlODY3ZmVhZTQyZXgxNzkwMTU2NDU5MDIyNDg2Njg010122026-09-23 09:40:59.050 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3610132026-09-23 09:40:59.050 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10142026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)10152026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (4.75ms)10162026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010172026/09/23 09:40:59 OK 20260905000000_add_claims.sql (5ms)10182026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures10192026/09/23 09:40:59 OK 20241026095416_initial_model.sql (13.57ms)10202026/09/23 09:40:59 OK 20241026095416_initial_model.sql (14.46ms)10212026/09/23 09:40:59 OK 20260905000000_add_claims.sql (7.33ms)10222026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)10232026/09/23 09:40:59 OK 20251218171726_add_pins.sql (5.14ms)10242026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.51ms)10252026/09/23 09:40:59 OK 20241026095416_initial_model.sql (14.87ms)10262026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (3.37ms)10272026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.14ms)10282026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010292026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (4.21ms)10302026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010312026/09/23 09:40:59 OK 20251218171726_add_pins.sql (5.16ms)10322026/09/23 09:40:59 OK 20241026095416_initial_model.sql (15.18ms)10332026/09/23 09:40:59 OK 20241026095416_initial_model.sql (16.17ms)10342026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.73ms)10352026/09/23 09:40:59 goose: up to current file version: 210362026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)10372026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.85ms)10382026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)10392026/09/23 09:40:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTNmYThjNDEtNjU1ZS00ZDI4LWI3OTAtNjkxYjY1MTgzZDIzLjgyMDBhYmUwLWI5ZjQtNDkzYS1hMmY3LWNlODY3ZmVhZTQyZXgxNzkwMTU2NDU5MDIyNDg2Njg0 parts=11040--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.34s)1041=== CONT TestGCBugBareHashReferences10422026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.92ms)10432026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.96ms)10442026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)10452026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)10462026/09/23 09:40:59 OK 20251218171726_add_pins.sql (4.31ms)10472026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)10482026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.22ms)10492026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)10502026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.17ms)10512026/09/23 09:40:59 OK 2_object_stats_trigger.sql (2.55ms)10522026/09/23 09:40:59 goose: up to current file version: 210532026/09/23 09:40:59 OK 2_object_stats_trigger.sql (3.38ms)10542026/09/23 09:40:59 goose: up to current file version: 210552026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.25ms)10562026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.75ms)10572026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.67ms)10582026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)10592026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.29ms)10602026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010612026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.72ms)10622026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)10632026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)10642026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.09ms)10652026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010662026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)10672026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.08ms)10682026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010692026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.22ms)10702026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.61ms)10712026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.64ms)10722026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.16ms)10732026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.95ms)10742026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.89ms)10752026/09/23 09:40:59 goose: up to current file version: 210762026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.55ms)10772026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.99ms)10782026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.3ms)10792026/09/23 09:40:59 OK 2_object_stats_trigger.sql (970.33µs)10802026/09/23 09:40:59 goose: up to current file version: 210812026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.21ms)10822026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010832026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.65ms)10842026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010852026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.39ms)10862026/09/23 09:40:59 goose: up to current file version: 210872026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)10882026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.82ms)10892026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010902026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.84ms)10912026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000010922026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.07ms)10932026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.02ms)10942026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.79ms)10952026/09/23 09:40:59 goose: up to current file version: 210962026-09-23 09:40:59.075 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3610972026-09-23 09:40:59.075 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10982026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.89ms)10992026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.1ms)11002026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.61ms)11012026/09/23 09:40:59 OK 2_object_stats_trigger.sql (2.74ms)11022026/09/23 09:40:59 goose: up to current file version: 211032026-09-23 09:40:59.077 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3611042026-09-23 09:40:59.077 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.69ms)11062026/09/23 09:40:59 goose: up to current file version: 211072026/09/23 09:40:59 OK 2_object_stats_trigger.sql (2.6ms)11082026/09/23 09:40:59 goose: up to current file version: 211092026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)11102026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures11112026/09/23 09:40:59 OK 20260905000000_add_claims.sql (5.91ms)11122026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.89ms)11132026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000011142026/09/23 09:40:59 OK 1_commit_pending_closure.sql (4.09ms)11152026/09/23 09:40:59 OK 20241026095416_initial_model.sql (13.03ms)11162026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.26ms)11172026/09/23 09:40:59 goose: up to current file version: 21118--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.38s)1119=== CONT TestLeadEndsOnShutdown11202026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)11212026/09/23 09:40:59 OK 20241026095416_initial_model.sql (12.44ms)11222026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.31ms)11232026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)11242026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)11252026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures11262026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures11272026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures11282026/09/23 09:40:59 OK 20251218171726_add_pins.sql (9.79ms)11292026/09/23 09:40:59 OK 20260905000000_add_claims.sql (8.86ms)11302026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)11312026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.21ms)11322026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000011332026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.37ms)11342026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.99ms)11352026/09/23 09:40:59 OK 2_object_stats_trigger.sql (827.62µs)11362026/09/23 09:40:59 goose: up to current file version: 211372026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (1.85ms)11382026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000011392026/09/23 09:40:59 INFO Received cleanup request method=DELETE path=/api/pending_closures11402026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.57ms)11412026-09-23 09:40:59.124 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3611422026-09-23 09:40:59.124 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.94ms)11442026/09/23 09:40:59 goose: up to current file version: 211452026/09/23 09:40:59 INFO Aborted multipart uploads count=011462026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/23 09:40:59 INFO Received cleanup request method=DELETE path=/api/pending_closures11482026/09/23 09:40:59 INFO Aborted multipart uploads count=111492026/09/23 09:40:59 OK 20241026095416_initial_model.sql (12.07ms)11502026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)11512026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11522026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.12ms)11532026-09-23 09:40:59.145 UTC [642] ERROR: Closure does not exist: id=111542026-09-23 09:40:59.145 UTC [642] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11552026-09-23 09:40:59.145 UTC [642] STATEMENT: -- name: CommitPendingClosure :exec1156 SELECT commit_pending_closure($1::bigint)1157 1158--- PASS: TestService_cleanupPendingClosuresHandler (0.43s)1159=== CONT TestLeadElectsOneAndHandsOver11602026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures11612026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)11622026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.88ms)11632026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.13ms)11642026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000011652026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.44ms)11662026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.01ms)11672026/09/23 09:40:59 goose: up to current file version: 211682026-09-23 09:40:59.161 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611692026-09-23 09:40:59.161 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1170--- PASS: TestService_Rustfstest (0.44s)1171=== CONT TestResolveDBConnectionString1172=== RUN TestResolveDBConnectionString/flag_wins1173=== PAUSE TestResolveDBConnectionString/flag_wins1174=== RUN TestResolveDBConnectionString/file_when_flag_empty1175=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1176=== RUN TestResolveDBConnectionString/missing_file_is_an_error1177=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1178=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1179=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1180=== RUN TestResolveDBConnectionString/nothing_configured1181=== PAUSE TestResolveDBConnectionString/nothing_configured1182=== CONT TestPinProtectsFromGC11832026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.37ms)11842026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)11852026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.47ms)11862026/09/23 09:40:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11872026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (6.6ms)11882026/09/23 09:40:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1189--- PASS: TestCompleteMultipartUnregistered (0.48s)1190=== CONT TestClientSharedPathCommittedMidPush11912026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.91ms)11922026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.38ms)11932026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000011942026-09-23 09:40:59.196 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611952026-09-23 09:40:59.196 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11962026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.48ms)11972026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.36ms)11982026/09/23 09:40:59 goose: up to current file version: 211992026/09/23 09:40:59 OK 20241026095416_initial_model.sql (8.78ms)12002026/09/23 09:40:59 INFO Starting HTTP server address=127.0.0.1:4664512012026/09/23 09:40:59 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket98114055/001/proxy.sock12022026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)12032026/09/23 09:40:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"12042026/09/23 09:40:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1205--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.42s)1206=== CONT TestClientWithDependencies12072026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.75ms)12082026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)12092026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.03ms)12102026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (9.86ms)12112026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000012122026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.23ms)12132026/09/23 09:40:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12142026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures12152026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.93ms)12162026/09/23 09:40:59 goose: up to current file version: 212172026-09-23 09:40:59.252 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3612182026-09-23 09:40:59.252 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026-09-23 09:40:59.266 UTC [689] ERROR: relation "goose_db_version" does not exist at character 3612202026-09-23 09:40:59.266 UTC [689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12212026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.3ms)12222026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)12232026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.54ms)12242026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)12252026/09/23 09:40:59 OK 20241026095416_initial_model.sql (7.87ms)12262026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)12272026/09/23 09:40:59 OK 20260905000000_add_claims.sql (4.81ms)12282026-09-23 09:40:59.283 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3612292026-09-23 09:40:59.283 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.88ms)12312026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.48ms)12322026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000001233--- PASS: TestObjectStatsTrigger (0.49s)1234=== CONT TestService_ReadScope_PublicByDefault12352026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures12362026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)12372026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.53ms)12382026/09/23 09:40:59 OK 2_object_stats_trigger.sql (963.6µs)12392026/09/23 09:40:59 goose: up to current file version: 212402026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.04ms)12412026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (1.61ms)12422026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000012432026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.9ms)12442026/09/23 09:40:59 OK 20241026095416_initial_model.sql (7.86ms)12452026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1ms)12462026/09/23 09:40:59 goose: up to current file version: 212472026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)12482026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.7ms)12492026-09-23 09:40:59.301 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3612502026-09-23 09:40:59.301 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12512026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (2.85ms)12522026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.04ms)12532026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.03ms)12542026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000012552026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.34ms)12562026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.57ms)12572026/09/23 09:40:59 goose: up to current file version: 212582026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures12592026/09/23 09:40:59 OK 20241026095416_initial_model.sql (8.24ms)12602026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)12612026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.75ms)12622026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)12632026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.68ms)12642026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (1.49ms)12652026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000012662026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.97ms)12672026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.42ms)12682026/09/23 09:40:59 goose: up to current file version: 212692026/09/23 09:40:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12702026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures12712026/09/23 09:40:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1272--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.54s)12732026/09/23 09:40:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1274=== CONT TestClientIntegration1275=== CONT TestClientErrorHandling1276=== RUN TestClientErrorHandling/InvalidStorePath1277--- PASS: TestService_NativeMTLS (0.53s)1278=== PAUSE TestClientErrorHandling/InvalidStorePath1279=== RUN TestClientErrorHandling/InvalidAuthToken1280=== PAUSE TestClientErrorHandling/InvalidAuthToken1281=== RUN TestClientErrorHandling/ServerNotAvailable1282=== PAUSE TestClientErrorHandling/ServerNotAvailable1283=== CONT TestClientCADerivations12842026-09-23 09:40:59.360 UTC [698] ERROR: relation "goose_db_version" does not exist at character 3612852026-09-23 09:40:59.360 UTC [698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12862026/09/23 09:40:59 OK 20241026095416_initial_model.sql (17.46ms)12872026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)12882026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.95ms)12892026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)12902026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.36ms)12912026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.31ms)12922026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000012932026/09/23 09:40:59 INFO Received cleanup request method=DELETE path=/api/pending_closures12942026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.57ms)1295=== NAME TestNARDeduplicationMetadataUploadBug1296 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2789035218/001/store/d3c55acwl3icyqq6bxj2ddfhy43w17fz-file1.txt12972026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.88ms)12982026/09/23 09:40:59 goose: up to current file version: 212992026/09/23 09:40:59 INFO Aborted multipart uploads count=11300--- PASS: TestMultipartCleanup (0.62s)1301=== CONT TestCacheStatsHandler13022026/09/23 09:40:59 WARN readiness check failed error="closed pool"1303--- PASS: TestService_readinessHandler (0.61s)1304=== CONT TestCacheConfigHandler1305=== RUN TestCacheConfigHandler/full_config,_no_issuer1306=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1307=== RUN TestCacheConfigHandler/no_cache_url_configured1308=== PAUSE TestCacheConfigHandler/no_cache_url_configured1309=== RUN TestCacheConfigHandler/no_signing_keys1310=== PAUSE TestCacheConfigHandler/no_signing_keys1311=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1312=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1313=== CONT TestReadProxy40413142026-09-23 09:40:59.427 UTC [719] ERROR: relation "goose_db_version" does not exist at character 3613152026-09-23 09:40:59.427 UTC [719] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13162026-09-23 09:40:59.430 UTC [722] ERROR: relation "goose_db_version" does not exist at character 3613172026-09-23 09:40:59.430 UTC [722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13182026/09/23 09:40:59 OK 20241026095416_initial_model.sql (8.67ms)13192026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)13202026/09/23 09:40:59 OK 20241026095416_initial_model.sql (8.28ms)13212026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)13222026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.98ms)13232026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.24ms)13242026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)13252026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)13262026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.2ms)13272026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.73ms)13282026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.35ms)13292026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000013302026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.64ms)13312026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000013322026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.32ms)13332026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.82ms)13342026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.62ms)13352026/09/23 09:40:59 goose: up to current file version: 213362026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.38ms)13372026/09/23 09:40:59 goose: up to current file version: 213382026/09/23 09:40:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1339--- PASS: TestService_healthCheckHandler (0.67s)1340=== CONT TestReadProxyConditionalGet13412026/09/23 09:40:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13422026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures13432026/09/23 09:40:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13442026/09/23 09:40:59 INFO Uploading d3c55acwl3icyqq6bxj2ddfhy43w17fz-file1.txt (160B)13452026/09/23 09:40:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTNmYThjNDEtNjU1ZS00ZDI4LWI3OTAtNjkxYjY1MTgzZDIzLjBjZDI2YjBiLTc0NDUtNGJlNi1iOTFhLTJhOTdmYjM3YWE2MngxNzkwMTU2NDU5MDU4OTU3OTQ1 parts=1013462026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13472026/09/23 09:40:59 INFO Completed upload id=113482026/09/23 09:40:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13492026-09-23 09:40:59.511 UTC [780] ERROR: relation "goose_db_version" does not exist at character 3613502026-09-23 09:40:59.511 UTC [780] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13512026/09/23 09:40:59 WARN Failed to register uploaded object key=d3c55acwl3icyqq6bxj2ddfhy43w17fz.ls error="server returned 404: 404 page not found\n"13522026/09/23 09:40:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13532026/09/23 09:40:59 INFO Signed narinfos id=1 count=113542026-09-23 09:40:59.512 UTC [781] ERROR: relation "goose_db_version" does not exist at character 3613552026-09-23 09:40:59.512 UTC [781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/09/23 09:40:59 INFO Uploading 1 narinfos13572026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures13582026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures13592026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13602026/09/23 09:40:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13612026/09/23 09:40:59 WARN Found objects in DB but missing from S3, will re-upload count=113622026/09/23 09:40:59 WARN Failed to register uploaded object key=d3c55acwl3icyqq6bxj2ddfhy43w17fz.narinfo error="server returned 404: 404 page not found\n"1363--- PASS: TestService_verifyS3Integrity (0.80s)1364=== CONT TestReadProxyRootRedirectsToIndexHTML13652026/09/23 09:40:59 INFO Completed upload id=113662026/09/23 09:40:59 INFO Upload complete. (72ms)1367=== NAME TestNARDeduplicationMetadataUploadBug1368 metadata_upload_test.go:54: Retrieved narinfo from S3:1369 StorePath: /build/TestNARDeduplicationMetadataUploadBug2789035218/001/store/d3c55acwl3icyqq6bxj2ddfhy43w17fz-file1.txt1370 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1371 Compression: zstd1372 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1373 NarSize: 1601374 References: 1375 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1376 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)13772026/09/23 09:40:59 OK 20241026095416_initial_model.sql (10.43ms)1378 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):13792026/09/23 09:40:59 OK 20241026095416_initial_model.sql (10.62ms)1380 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13812026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)13822026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)13832026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.62ms)13842026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.78ms)1385--- PASS: TestMetricsInventory (0.73s)1386=== CONT TestReadProxyHead13872026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)13882026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)13892026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.13ms)13902026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.96ms)13912026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.63ms)13922026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000013932026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.98ms)13942026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000013952026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.48ms)13962026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.97ms)13972026/09/23 09:40:59 OK 2_object_stats_trigger.sql (946.38µs)13982026/09/23 09:40:59 goose: up to current file version: 213992026/09/23 09:40:59 OK 2_object_stats_trigger.sql (781.4µs)14002026/09/23 09:40:59 goose: up to current file version: 214012026/09/23 09:40:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14022026-09-23 09:40:59.555 UTC [787] ERROR: relation "goose_db_version" does not exist at character 3614032026-09-23 09:40:59.555 UTC [787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1404=== NAME TestNARDeduplicationMetadataUploadBug1405 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2789035218/001/store/wrnvyinh4l1532j3ciaiycf9kd1bdw0z-file2.txt14062026/09/23 09:40:59 OK 20241026095416_initial_model.sql (8.27ms)14072026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)14082026/09/23 09:40:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14092026/09/23 09:40:59 WARN Refused reserved pin name=worker-x86_64-linux14102026/09/23 09:40:59 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTNmYThjNDEtNjU1ZS00ZDI4LWI3OTAtNjkxYjY1MTgzZDIzLjhlYmJlY2FlLTU2YzktNGI2Yi1iNTFkLThkMmVhOTc2ZmMzMngxNzkwMTU2NDU5MTEzMDA0NzIz parts=1014112026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.92ms)14122026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14132026/09/23 09:40:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14142026/09/23 09:40:59 INFO Received create pin request method=POST path=/api/pins/my-app14152026/09/23 09:40:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1416--- PASS: TestCreatePin_ReservedPins (0.78s)1417=== CONT TestReadProxyInvalidPath14182026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)14192026/09/23 09:40:59 INFO Completed upload id=114202026/09/23 09:40:59 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014212026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.76ms)14222026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures14232026/09/23 09:40:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures14242026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (4.61ms)14252026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000001426--- PASS: TestResurrectedObjectNotDeleted (0.79s)1427=== CONT TestRedundantMultipartUpload14282026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.27ms)14292026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.68ms)14302026/09/23 09:40:59 goose: up to current file version: 214312026/09/23 09:40:59 INFO Aborted multipart uploads count=014322026/09/23 09:40:59 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=014332026/09/23 09:40:59 INFO Vacuumed table table=pending_closures14342026/09/23 09:40:59 INFO Vacuumed table table=pending_objects14352026-09-23 09:40:59.617 UTC [829] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-23 09:40:59.617 UTC [829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026-09-23 09:40:59.628 UTC [830] ERROR: relation "goose_db_version" does not exist at character 3614382026-09-23 09:40:59.628 UTC [830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026/09/23 09:40:59 INFO Vacuumed table table=multipart_uploads14402026/09/23 09:40:59 INFO Vacuumed table table=closures14412026/09/23 09:40:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14422026/09/23 09:40:59 INFO Vacuumed table table=objects14432026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures14442026/09/23 09:40:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14452026/09/23 09:40:59 INFO Aborted multipart uploads count=014462026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.78ms)1447=== NAME TestClientMultipleUploads1448 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2009598143/001/store/ypgxi455i23kxv5qclh0z0njfrjiqa4x-test-file-0.txt14492026/09/23 09:40:59 WARN Force mode enabled - objects will be deleted immediately without grace period14502026/09/23 09:40:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14512026/09/23 09:40:59 INFO Signed narinfos id=2 count=114522026/09/23 09:40:59 WARN Failed to register uploaded object key=wrnvyinh4l1532j3ciaiycf9kd1bdw0z.ls error="server returned 404: 404 page not found\n"14532026/09/23 09:40:59 INFO Uploading 1 narinfos14542026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (5.59ms)14552026/09/23 09:40:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014562026/09/23 09:40:59 INFO Vacuumed table table=pending_closures14572026/09/23 09:40:59 INFO Vacuumed table table=pending_objects14582026/09/23 09:40:59 INFO Vacuumed table table=multipart_uploads14592026/09/23 09:40:59 INFO Vacuumed table table=closures14602026/09/23 09:40:59 INFO Vacuumed table table=objects14612026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14622026/09/23 09:40:59 WARN Failed to register uploaded object key=wrnvyinh4l1532j3ciaiycf9kd1bdw0z.narinfo error="server returned 404: 404 page not found\n"1463--- PASS: TestGCMetrics (0.62s)1464=== CONT TestService_ReadAuthMiddleware14652026/09/23 09:40:59 OK 20241026095416_initial_model.sql (22.15ms)14662026/09/23 09:40:59 INFO Completed upload id=214672026/09/23 09:40:59 OK 20251218171726_add_pins.sql (20.65ms)14682026/09/23 09:40:59 INFO Upload complete. (65ms)1469=== NAME TestNARDeduplicationMetadataUploadBug1470 metadata_upload_test.go:76: Retrieved narinfo from S3:1471 StorePath: /build/TestNARDeduplicationMetadataUploadBug2789035218/001/store/wrnvyinh4l1532j3ciaiycf9kd1bdw0z-file2.txt1472 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1473 Compression: zstd1474 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1475 NarSize: 1601476 References: 1477 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14782026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (12.67ms)1479 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1480 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1481 {"version":1,"root":{"type":"regular","size":44}}14822026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)14832026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.89ms)14842026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.97ms)1485--- PASS: TestNARDeduplicationMetadataUploadBug (0.87s)1486=== CONT TestReadRedirectUsesPublicS3URL14872026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)14882026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.72ms)14892026-09-23 09:40:59.678 UTC [884] ERROR: relation "goose_db_version" does not exist at character 3614902026-09-23 09:40:59.678 UTC [884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14912026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000001492=== NAME TestClientMultipleUploads1493 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2009598143/001/store/79l3rl1znq2vff9rc6ryirnzlj271b0h-test-file-1.txt14942026-09-23 09:40:59.681 UTC [885] ERROR: relation "goose_db_version" does not exist at character 3614952026-09-23 09:40:59.681 UTC [885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14962026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.75ms)14972026/09/23 09:40:59 OK 20260905000000_add_claims.sql (4.4ms)14982026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.28ms)14992026/09/23 09:40:59 goose: up to current file version: 215002026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (1.61ms)15012026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000015022026/09/23 09:40:59 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001503--- PASS: TestService_createPendingClosureHandler (0.97s)1504=== CONT TestService_RequireScope_OIDC15052026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.65ms)15062026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.5ms)15072026/09/23 09:40:59 goose: up to current file version: 215082026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.57ms)15092026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)15102026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.8ms)15112026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)15122026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.92ms)15132026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.54ms)15142026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)15152026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)15162026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.99ms)15172026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.49ms)15182026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000015192026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.99ms)15202026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.37ms)15212026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.79ms)15222026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000015232026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.07ms)15242026/09/23 09:40:59 goose: up to current file version: 215252026/09/23 09:40:59 INFO lead: acquired remote=192.0.2.1:123415262026/09/23 09:40:59 INFO lead: released remote=192.0.2.1:123415272026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.73ms)1528--- PASS: TestLeadEndsOnShutdown (0.62s)1529=== CONT TestReadProxyRangeRequest15302026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.33ms)1531=== NAME TestClientMultipleUploads15322026/09/23 09:40:59 goose: up to current file version: 21533 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2009598143/001/store/6imxqq6cpszjifvdzf6gyladapk6psbb-test-file-2.txt15342026/09/23 09:40:59 INFO lead: acquired remote=192.0.2.1:123415352026/09/23 09:40:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36805/oidc15362026-09-23 09:40:59.776 UTC [929] ERROR: relation "goose_db_version" does not exist at character 3615372026-09-23 09:40:59.776 UTC [929] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15382026-09-23 09:40:59.777 UTC [930] ERROR: relation "goose_db_version" does not exist at character 3615392026-09-23 09:40:59.777 UTC [930] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15402026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.95ms)15412026/09/23 09:40:59 OK 20241026095416_initial_model.sql (10.36ms)15422026/09/23 09:40:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15432026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures15442026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)15452026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)15462026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.03ms)15472026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.82ms)15482026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)15492026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)15502026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures15512026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures15522026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.44ms)15532026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.28ms)15542026-09-23 09:40:59.805 UTC [957] ERROR: relation "goose_db_version" does not exist at character 3615552026-09-23 09:40:59.805 UTC [957] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15562026/09/23 09:40:59 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15572026/09/23 09:40:59 INFO Uploading 6imxqq6cpszjifvdzf6gyladapk6psbb-test-file-2.txt (160B)15582026/09/23 09:40:59 INFO Uploading 79l3rl1znq2vff9rc6ryirnzlj271b0h-test-file-1.txt (160B)15592026/09/23 09:40:59 INFO Uploading ypgxi455i23kxv5qclh0z0njfrjiqa4x-test-file-0.txt (160B)1560=== NAME TestOrphanedObjectsGC1561 orphaned_objects_gc_test.go:290: GC Test Summary:15622026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.74ms)1563 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A15642026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000001565 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B15662026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.97ms)1567 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)15682026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000001569 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1570 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1571--- PASS: TestOrphanedObjectsGC (1.08s)1572=== CONT TestService_AuthMiddleware_OIDC15732026/09/23 09:40:59 OK 1_commit_pending_closure.sql (2.59ms)15742026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3ms)15752026/09/23 09:40:59 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15762026/09/23 09:40:59 WARN Failed to register uploaded object key=79l3rl1znq2vff9rc6ryirnzlj271b0h.ls error="server returned 404: 404 page not found\n"15772026/09/23 09:40:59 WARN Failed to register uploaded object key=6imxqq6cpszjifvdzf6gyladapk6psbb.ls error="server returned 404: 404 page not found\n"15782026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.48ms)15792026/09/23 09:40:59 goose: up to current file version: 215802026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.62ms)15812026/09/23 09:40:59 goose: up to current file version: 215822026/09/23 09:40:59 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15832026/09/23 09:40:59 WARN Failed to register uploaded object key=ypgxi455i23kxv5qclh0z0njfrjiqa4x.ls error="server returned 404: 404 page not found\n"15842026/09/23 09:40:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15852026/09/23 09:40:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15862026/09/23 09:40:59 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15872026/09/23 09:40:59 INFO Signed narinfos id=1 count=115882026/09/23 09:40:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15892026/09/23 09:40:59 INFO Signed narinfos id=2 count=115902026/09/23 09:40:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15912026/09/23 09:40:59 INFO Signed narinfos id=3 count=115922026/09/23 09:40:59 INFO Uploading 3 narinfos15932026/09/23 09:40:59 WARN Failed to register uploaded object key=ypgxi455i23kxv5qclh0z0njfrjiqa4x.narinfo error="server returned 404: 404 page not found\n"15942026/09/23 09:40:59 WARN Failed to register uploaded object key=6imxqq6cpszjifvdzf6gyladapk6psbb.narinfo error="server returned 404: 404 page not found\n"15952026/09/23 09:40:59 OK 20241026095416_initial_model.sql (8.09ms)15962026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15972026/09/23 09:40:59 WARN Failed to register uploaded object key=79l3rl1znq2vff9rc6ryirnzlj271b0h.narinfo error="server returned 404: 404 page not found\n"15982026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)15992026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.14ms)16002026/09/23 09:40:59 INFO Completed upload id=116012026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16022026/09/23 09:40:59 INFO Completed upload id=216032026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16042026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)16052026/09/23 09:40:59 INFO Completed upload id=316062026/09/23 09:40:59 INFO Upload complete. (75ms)1607=== NAME TestClientMultipleUploads1608 client_integration_test.go:369: Uploaded 3 paths in 110.778203ms16092026/09/23 09:40:59 OK 20260905000000_add_claims.sql (2.69ms)16102026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.02ms)16112026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000016122026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.56ms)16132026/09/23 09:40:59 OK 2_object_stats_trigger.sql (844.5µs)16142026/09/23 09:40:59 goose: up to current file version: 216152026/09/23 09:40:59 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTNmYThjNDEtNjU1ZS00ZDI4LWI3OTAtNjkxYjY1MTgzZDIzLmRiNjM5ZDk0LWMzM2MtNGQ0OS04OGJmLTY5ZDQ1NDQwNGJmMXgxNzkwMTU2NDU5MjQ5NjAyNTc2 parts=1216162026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures1617--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.11s)1618=== CONT TestReadRedirectKeepsNarinfoProxied1619--- PASS: TestClientMultipleUploads (0.89s)1620=== CONT TestReadRedirectNar16212026-09-23 09:40:59.846 UTC [993] ERROR: relation "goose_db_version" does not exist at character 3616222026-09-23 09:40:59.846 UTC [993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1623=== NAME TestPinProtectsFromGC1624 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3406279614/001/store/jr4pvd6nfskdpr4ydxcs5msyrajn9jjq-pinned-file.txt1625 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3406279614/001/store/24pa62290ga5bzg4y4yiy7c23fz4lwdl-unpinned-file.txt1626--- PASS: TestService_ReadScope_PublicByDefault (0.57s)1627=== CONT TestReadProxyDisabled16282026/09/23 09:40:59 OK 20241026095416_initial_model.sql (12.49ms)16292026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)16302026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.32ms)16312026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)16322026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.26ms)16332026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (2.66ms)16342026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000016352026/09/23 09:40:59 OK 1_commit_pending_closure.sql (1.87ms)16362026/09/23 09:40:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41535/oidc16372026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.65ms)16382026/09/23 09:40:59 goose: up to current file version: 216392026/09/23 09:40:59 INFO lead: released remote=192.0.2.1:12341640--- PASS: TestGCBugBareHashReferences (0.86s)1641=== CONT TestReadProxyNarinfoAlreadyDecompressed16422026/09/23 09:40:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16432026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures1644=== NAME TestClientWithDependencies1645 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2638770356/001/store/4lp14hs02y5f83xipgwlb082a30i3hyk-test-script1646=== NAME TestClientIntegration1647 client_integration_test.go:286: Created store path: /build/TestClientIntegration709082565/002/store/gfc72bhqzch65xichsycb1jwzb1qxmz9-test-file.txt16482026/09/23 09:40:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16492026/09/23 09:40:59 INFO Uploading jr4pvd6nfskdpr4ydxcs5msyrajn9jjq-pinned-file.txt (128B)16502026/09/23 09:40:59 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16512026/09/23 09:40:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1652--- PASS: TestReadProxy404 (0.52s)1653=== CONT TestReadProxyNarStreaming16542026/09/23 09:40:59 WARN Failed to register uploaded object key=jr4pvd6nfskdpr4ydxcs5msyrajn9jjq.ls error="server returned 404: 404 page not found\n"16552026/09/23 09:40:59 INFO Signed narinfos id=1 count=116562026/09/23 09:40:59 INFO Uploading 1 narinfos16572026/09/23 09:40:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16582026/09/23 09:40:59 WARN Failed to register uploaded object key=jr4pvd6nfskdpr4ydxcs5msyrajn9jjq.narinfo error="server returned 404: 404 page not found\n"16592026-09-23 09:40:59.943 UTC [1148] ERROR: relation "goose_db_version" does not exist at character 3616602026-09-23 09:40:59.943 UTC [1148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16612026/09/23 09:40:59 INFO lead: acquired remote=192.0.2.1:123416622026-09-23 09:40:59.948 UTC [1165] ERROR: relation "goose_db_version" does not exist at character 3616632026-09-23 09:40:59.948 UTC [1165] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16642026/09/23 09:40:59 INFO Completed upload id=116652026/09/23 09:40:59 INFO Upload complete. (66ms)1666=== NAME TestClientWithDependencies1667 client_integration_test.go:615: Found 1 dependencies (including self)16682026/09/23 09:40:59 INFO lead: released remote=192.0.2.1:12341669--- PASS: TestLeadElectsOneAndHandsOver (0.81s)1670=== CONT TestReadProxyNarinfo16712026-09-23 09:40:59.956 UTC [1186] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-23 09:40:59.956 UTC [1186] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.2ms)16742026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)16752026/09/23 09:40:59 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16762026/09/23 09:40:59 INFO Received uploads request method=POST path=/api/pending_closures16772026/09/23 09:40:59 OK 20251218171726_add_pins.sql (2.7ms)16782026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)16792026/09/23 09:40:59 OK 20260905000000_add_claims.sql (3.28ms)16802026/09/23 09:40:59 OK 20241026095416_initial_model.sql (9.16ms)16812026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)16822026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (3.44ms)16832026/09/23 09:40:59 goose: successfully migrated database to version: 2026092000000016842026/09/23 09:40:59 OK 20241026095416_initial_model.sql (19.48ms)16852026/09/23 09:40:59 OK 20251218171726_add_pins.sql (3.43ms)16862026/09/23 09:40:59 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)16872026/09/23 09:40:59 OK 1_commit_pending_closure.sql (3.11ms)1688--- PASS: TestCacheStatsHandler (0.56s)1689=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16902026/09/23 09:40:59 OK 2_object_stats_trigger.sql (1.67ms)16912026/09/23 09:40:59 goose: up to current file version: 216922026-09-23 09:40:59.982 UTC [1242] ERROR: relation "goose_db_version" does not exist at character 3616932026-09-23 09:40:59.982 UTC [1242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16942026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (4ms)16952026/09/23 09:40:59 OK 20251218171726_add_pins.sql (5.03ms)16962026/09/23 09:40:59 OK 20260905000000_add_claims.sql (12.85ms)16972026/09/23 09:40:59 OK 20260628120000_add_object_size_and_stats.sql (14ms)16982026/09/23 09:40:59 OK 20260920000000_drop_claims.sql (4.2ms)16992026/09/23 09:40:59 goose: successfully migrated database to version: 202609200000001700--- PASS: TestReadProxyConditionalGet (0.52s)1701=== CONT TestService_AuthMiddleware_MTLSProxyHeader1702=== NAME TestClientCADerivations1703 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1598149617/001/store/bhsdxz98akj8as4xbm483al8bh23cv1q-ca-test17042026/09/23 09:41:00 OK 1_commit_pending_closure.sql (3.67ms)17052026/09/23 09:41:00 OK 20260905000000_add_claims.sql (6.61ms)17062026/09/23 09:41:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17072026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures17082026/09/23 09:41:00 OK 2_object_stats_trigger.sql (1.74ms)17092026/09/23 09:41:00 goose: up to current file version: 217102026/09/23 09:41:00 OK 20241026095416_initial_model.sql (10.89ms)17112026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (4.71ms)17122026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000017132026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)17142026/09/23 09:41:00 OK 1_commit_pending_closure.sql (3.28ms)17152026/09/23 09:41:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17162026/09/23 09:41:00 INFO Uploading gfc72bhqzch65xichsycb1jwzb1qxmz9-test-file.txt (152B)17172026/09/23 09:41:00 OK 2_object_stats_trigger.sql (2.44ms)17182026/09/23 09:41:00 goose: up to current file version: 217192026/09/23 09:41:00 OK 20251218171726_add_pins.sql (3.6ms)17202026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17212026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17222026/09/23 09:41:00 WARN Failed to register uploaded object key=gfc72bhqzch65xichsycb1jwzb1qxmz9.ls error="server returned 404: 404 page not found\n"17232026/09/23 09:41:00 INFO Signed narinfos id=1 count=117242026/09/23 09:41:00 INFO Uploading 1 narinfos17252026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)17262026/09/23 09:41:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17272026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures1728--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.50s)1729=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17302026/09/23 09:41:00 INFO Received uploads request method=POST path=/1731=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17322026/09/23 09:41:00 INFO Received request for more parts method=POST path=/1733=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17342026/09/23 09:41:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17352026/09/23 09:41:00 INFO Received complete multipart upload request method=POST path=/17362026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures1737=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17382026/09/23 09:41:00 INFO Received uploads request method=POST path=/1739--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1740 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1741 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1742 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1743 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)17442026-09-23 09:41:00.023 UTC [1354] ERROR: relation "goose_db_version" does not exist at character 3617452026-09-23 09:41:00.023 UTC [1354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1746=== CONT TestProxyWriteTimeout/narinfo1747=== CONT TestProxyWriteTimeout/10_GiB_nar1748=== CONT TestProxyWriteTimeout/1_GiB_nar1749=== CONT TestProxyWriteTimeout/unknown_size1750--- PASS: TestProxyWriteTimeout (0.08s)1751 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1752 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1753 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1754 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1755=== CONT TestServerTLSConfig/no_client_CA1756=== CONT TestServerTLSConfig/not_a_PEM_file17572026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17582026/09/23 09:41:00 WARN Failed to register uploaded object key=gfc72bhqzch65xichsycb1jwzb1qxmz9.narinfo error="server returned 404: 404 page not found\n"1759=== CONT TestServerTLSConfig/missing_CA_file1760--- PASS: TestServerTLSConfig (0.00s)1761 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1762 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1763 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1764=== CONT TestIsValidUploadKey/narinfo1765=== CONT TestIsValidUploadKey/unknown_type17662026/09/23 09:41:00 OK 20260905000000_add_claims.sql (4.57ms)1767=== CONT TestIsValidUploadKey/empty_key1768=== CONT TestIsValidUploadKey/absolute1769=== CONT TestIsValidUploadKey/traversal_nar1770=== CONT TestIsValidUploadKey/traversal1771=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1772=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1773=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1774=== CONT TestIsValidUploadKey/index.html1775=== CONT TestIsValidUploadKey/build_log_home-manager_file1776=== CONT TestIsValidUploadKey/build_log1777=== CONT TestIsValidUploadKey/listing1778=== CONT TestIsValidUploadKey/nar_plain1779=== CONT TestIsValidUploadKey/nar_xz1780=== CONT TestIsValidUploadKey/nar_zst1781=== CONT TestIsValidUploadKey/build_log_plus_in_name1782=== CONT TestIsValidUploadKey/realisation1783=== CONT TestIsValidUploadKey/nix-cache-info1784=== CONT TestIsValidUploadKey/realisation_plus_in_output1785=== CONT TestIsValidUploadKey/build_log_question_mark1786=== CONT TestIsValidUploadKey/build_log_equals1787--- PASS: TestIsValidUploadKey (0.09s)1788 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1789 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1790 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1791 --- PASS: TestIsValidUploadKey/absolute (0.00s)1792 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1793 --- PASS: TestIsValidUploadKey/traversal (0.00s)1794 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1796 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1797 --- PASS: TestIsValidUploadKey/index.html (0.00s)1798 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1799 --- PASS: TestIsValidUploadKey/build_log (0.00s)1800 --- PASS: TestIsValidUploadKey/listing (0.00s)1801 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1802 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1803 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1804 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1805 --- PASS: TestIsValidUploadKey/realisation (0.00s)1806 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1807 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1808 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1809 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1810=== CONT TestParseSingleRange/none1811=== CONT TestParseSingleRange/start_far_past_EOF18122026/09/23 09:41:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1813=== CONT TestParseSingleRange/closed18142026/09/23 09:41:00 INFO Uploading 24pa62290ga5bzg4y4yiy7c23fz4lwdl-unpinned-file.txt (128B)1815=== CONT TestParseSingleRange/malformed_end_before_start1816=== CONT TestParseSingleRange/malformed_both_empty1817=== CONT TestParseSingleRange/malformed_no_dash1818=== CONT TestParseSingleRange/multi-range_ignored1819=== CONT TestParseSingleRange/unknown_unit1820=== CONT TestParseSingleRange/suffix_exceeds_size1821=== CONT TestParseSingleRange/start_past_EOF1822=== CONT TestParseSingleRange/single_byte1823=== CONT TestParseSingleRange/suffix1824=== CONT TestParseSingleRange/end_clamped_to_size1825=== CONT TestParseSingleRange/open-ended1826=== CONT TestIsValidCachePath/narinfo1827=== CONT TestIsValidCachePath/index.html1828=== CONT TestIsValidCachePath/short_hash1829=== CONT TestIsValidCachePath/wrong_extension1830=== CONT TestIsValidCachePath/leading_slash1831--- PASS: TestParseSingleRange (0.01s)1832 --- PASS: TestParseSingleRange/none (0.00s)1833 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1834 --- PASS: TestParseSingleRange/closed (0.00s)1835 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1836 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1837 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1838 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1839 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1840 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1841 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1842 --- PASS: TestParseSingleRange/single_byte (0.00s)1843 --- PASS: TestParseSingleRange/suffix (0.00s)1844 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1845 --- PASS: TestParseSingleRange/open-ended (0.00s)1846=== CONT TestIsValidCachePath/invalid_char_e1847=== CONT TestIsValidCachePath/traversal_in_middle1848=== CONT TestIsValidCachePath/traversal_parent1849=== CONT TestIsValidCachePath/nar_uncompressed1850=== CONT TestIsValidCachePath/nix-cache-info1851=== CONT TestIsValidCachePath/realisation1852=== CONT TestIsValidCachePath/log1853=== CONT TestIsValidCachePath/ls1854=== CONT TestIsValidCachePath/nar_xz1855=== CONT TestIsValidCachePath/nar_bz21856=== CONT TestIsValidCachePath/nar_zst1857=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1858=== CONT TestIsValidCachePath/empty1859=== CONT TestIsValidCachePath/random_path1860=== CONT TestIsValidCachePath/invalid_char_u1861--- PASS: TestIsValidCachePath (0.01s)1862 --- PASS: TestIsValidCachePath/narinfo (0.00s)1863 --- PASS: TestIsValidCachePath/index.html (0.00s)1864 --- PASS: TestIsValidCachePath/short_hash (0.00s)1865 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1866 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1867 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1868 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1869 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1870 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1871 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1872 --- PASS: TestIsValidCachePath/realisation (0.00s)1873 --- PASS: TestIsValidCachePath/log (0.00s)1874 --- PASS: TestIsValidCachePath/ls (0.00s)1875 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1876 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1877 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1878 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1879 --- PASS: TestIsValidCachePath/empty (0.00s)1880 --- PASS: TestIsValidCachePath/random_path (0.00s)1881 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1882=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18832026/09/23 09:41:00 INFO Received request for more parts method=POST path=/18842026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (3.69ms)18852026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000018862026/09/23 09:41:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18872026/09/23 09:41:00 INFO Uploading 4lp14hs02y5f83xipgwlb082a30i3hyk-test-script (136B)18882026/09/23 09:41:00 WARN Failed to register uploaded object key=24pa62290ga5bzg4y4yiy7c23fz4lwdl.ls error="server returned 404: 404 page not found\n"18892026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18902026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18912026/09/23 09:41:00 INFO Signed narinfos id=2 count=118922026/09/23 09:41:00 INFO Uploading 1 narinfos18932026/09/23 09:41:00 OK 1_commit_pending_closure.sql (2.85ms)18942026/09/23 09:41:00 INFO Completed upload id=118952026/09/23 09:41:00 INFO Upload complete. (71ms)18962026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18972026/09/23 09:41:00 OK 2_object_stats_trigger.sql (2.3ms)18982026/09/23 09:41:00 goose: up to current file version: 218992026/09/23 09:41:00 WARN Failed to register uploaded object key=4lp14hs02y5f83xipgwlb082a30i3hyk.ls error="server returned 404: 404 page not found\n"19002026/09/23 09:41:00 WARN Failed to register uploaded object key=log/7jl9map2pvm6028ak2nckfibnr9a8pps-test-script.drv error="server returned 404: 404 page not found\n"19012026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19022026/09/23 09:41:00 INFO Signed narinfos id=1 count=11903=== NAME TestClientCADerivations1904 client_ca_test.go:139: Found 1 dependencies (including self)19052026/09/23 09:41:00 INFO Uploading 1 narinfos19062026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19072026/09/23 09:41:00 WARN Failed to register uploaded object key=24pa62290ga5bzg4y4yiy7c23fz4lwdl.narinfo error="server returned 404: 404 page not found\n"19082026/09/23 09:41:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19092026-09-23 09:41:00.038 UTC [1388] ERROR: relation "goose_db_version" does not exist at character 3619102026-09-23 09:41:00.038 UTC [1388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19112026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures19122026/09/23 09:41:00 OK 20241026095416_initial_model.sql (8.9ms)19132026/09/23 09:41:00 INFO Completed upload id=219142026/09/23 09:41:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19152026/09/23 09:41:00 INFO Uploading r09821lg9k5gkky7hc7ivncxqzg6vz8k-shared-dep (136B)19162026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19172026/09/23 09:41:00 INFO Upload complete. (51ms)19182026/09/23 09:41:00 WARN Failed to register uploaded object key=4lp14hs02y5f83xipgwlb082a30i3hyk.narinfo error="server returned 404: 404 page not found\n"19192026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)19202026/09/23 09:41:00 OK 20251218171726_add_pins.sql (2.65ms)19212026/09/23 09:41:00 WARN Failed to register uploaded object key=r09821lg9k5gkky7hc7ivncxqzg6vz8k.ls error="server returned 404: 404 page not found\n"19222026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19232026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19242026/09/23 09:41:00 INFO Signed narinfos id=2 count=119252026/09/23 09:41:00 INFO Uploading 1 narinfos19262026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)19272026/09/23 09:41:00 INFO Completed upload id=119282026/09/23 09:41:00 INFO Upload complete. (64ms)19292026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19302026/09/23 09:41:00 WARN Failed to register uploaded object key=r09821lg9k5gkky7hc7ivncxqzg6vz8k.narinfo error="server returned 404: 404 page not found\n"19312026-09-23 09:41:00.049 UTC [1392] ERROR: relation "goose_db_version" does not exist at character 3619322026-09-23 09:41:00.049 UTC [1392] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1933--- PASS: TestReadProxyHead (0.52s)1934=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19352026/09/23 09:41:00 INFO Received complete multipart upload request method=POST path=/1936=== NAME TestClientWithDependencies1937 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2638770356/001/store) requires matching store prefix19382026/09/23 09:41:00 OK 20260905000000_add_claims.sql (3.54ms)19392026/09/23 09:41:00 OK 20241026095416_initial_model.sql (8.83ms)19402026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (2.13ms)19412026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000019422026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)19432026/09/23 09:41:00 INFO Completed upload id=219442026/09/23 09:41:00 INFO Upload complete. (54ms)19452026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures1946--- PASS: TestClientWithDependencies (0.84s)1947=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19482026/09/23 09:41:00 INFO Received uploads request method=POST path=/19492026/09/23 09:41:00 OK 1_commit_pending_closure.sql (2.45ms)19502026/09/23 09:41:00 OK 20251218171726_add_pins.sql (3.15ms)19512026/09/23 09:41:00 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19522026/09/23 09:41:00 INFO Uploading jjlkfi1z2xki5zqhd1l55dw9z5a35540-top (224B)19532026/09/23 09:41:00 INFO Uploading r09821lg9k5gkky7hc7ivncxqzg6vz8k-shared-dep (136B)19542026/09/23 09:41:00 OK 2_object_stats_trigger.sql (1.7ms)19552026/09/23 09:41:00 goose: up to current file version: 219562026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)19572026/09/23 09:41:00 WARN Failed to register uploaded object key=jjlkfi1z2xki5zqhd1l55dw9z5a35540.ls error="server returned 404: 404 page not found\n"19582026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/04q9ylrm4jyf338nf335ff7461dsl2s8783bp5j0nxha71km1ps9.nar.zst error="server returned 404: 404 page not found\n"19592026/09/23 09:41:00 WARN Failed to register uploaded object key=r09821lg9k5gkky7hc7ivncxqzg6vz8k.ls error="server returned 404: 404 page not found\n"19602026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19612026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19622026/09/23 09:41:00 INFO Signed narinfos id=1 count=119632026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign19642026/09/23 09:41:00 INFO Signed narinfos id=3 count=119652026/09/23 09:41:00 OK 20260905000000_add_claims.sql (3.11ms)19662026/09/23 09:41:00 INFO Uploading 2 narinfos19672026/09/23 09:41:00 OK 20241026095416_initial_model.sql (9.23ms)19682026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (2.59ms)19692026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000019702026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)19712026/09/23 09:41:00 WARN Failed to register uploaded object key=r09821lg9k5gkky7hc7ivncxqzg6vz8k.narinfo error="server returned 404: 404 page not found\n"19722026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19732026/09/23 09:41:00 WARN Failed to register uploaded object key=jjlkfi1z2xki5zqhd1l55dw9z5a35540.narinfo error="server returned 404: 404 page not found\n"1974=== CONT TestResolveDBConnectionString/flag_wins1975=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1976=== CONT TestResolveDBConnectionString/nothing_configured1977=== CONT TestResolveDBConnectionString/missing_file_is_an_error19782026/09/23 09:41:00 INFO All 1 paths already cached1979=== CONT TestResolveDBConnectionString/file_when_flag_empty1980=== CONT TestClientErrorHandling/InvalidStorePath19812026/09/23 09:41:00 OK 1_commit_pending_closure.sql (3.21ms)19822026/09/23 09:41:00 OK 20251218171726_add_pins.sql (2.96ms)19832026/09/23 09:41:00 INFO Completed upload id=11984--- PASS: TestResolveDBConnectionString (0.00s)1985 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1986 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1987 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1988 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1989 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19902026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1991=== NAME TestClientIntegration1992 client_integration_test.go:312: Retrieved narinfo from S3:1993 StorePath: /build/TestClientIntegration709082565/002/store/gfc72bhqzch65xichsycb1jwzb1qxmz9-test-file.txt1994 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1995 Compression: zstd1996 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11997 NarSize: 1521998 References: 1999 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk120002026/09/23 09:41:00 OK 2_object_stats_trigger.sql (1.49ms)20012026/09/23 09:41:00 goose: up to current file version: 220022026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures20032026/09/23 09:41:00 INFO Completed upload id=320042026/09/23 09:41:00 INFO Upload complete. (151ms)2005 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2006 client_integration_test.go:313: Decompressed .ls content (64 bytes):2007 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2008 client_integration_test.go:316: Testing garbage collection...2009=== NAME TestClientSharedPathCommittedMidPush2010 client_integration_test.go:680: Retrieved narinfo from S3:2011 StorePath: /build/TestClientSharedPathCommittedMidPush1277206016/001/store/r09821lg9k5gkky7hc7ivncxqzg6vz8k-shared-dep2012 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2013 Compression: zstd2014 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822015 NarSize: 13620162026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)2017 References: 2018 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2019 client_integration_test.go:680: Retrieved narinfo from S3:2020 StorePath: /build/TestClientSharedPathCommittedMidPush1277206016/001/store/jjlkfi1z2xki5zqhd1l55dw9z5a35540-top2021 URL: nar/04q9ylrm4jyf338nf335ff7461dsl2s8783bp5j0nxha71km1ps9.nar.zst2022 Compression: zstd2023 NarHash: sha256:04q9ylrm4jyf338nf335ff7461dsl2s8783bp5j0nxha71km1ps92024 NarSize: 2242025 References: /build/TestClientSharedPathCommittedMidPush1277206016/001/store/r09821lg9k5gkky7hc7ivncxqzg6vz8k-shared-dep2026 CA: text:sha256:032bd520s20s4jx690zjlispj2kfzn8ny9f6l8riygf11l3nkcqa20272026/09/23 09:41:00 OK 20260905000000_add_claims.sql (3.12ms)20282026/09/23 09:41:00 INFO Received create pin request method=POST path=/api/pins/myapp20292026-09-23 09:41:00.080 UTC [1445] ERROR: relation "goose_db_version" does not exist at character 3620302026-09-23 09:41:00.080 UTC [1445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2031--- PASS: TestClientSharedPathCommittedMidPush (0.89s)2032=== CONT TestClientErrorHandling/ServerNotAvailable20332026/09/23 09:41:00 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3406279614/001/store/jr4pvd6nfskdpr4ydxcs5msyrajn9jjq-pinned-file.txt narinfo_key=jr4pvd6nfskdpr4ydxcs5msyrajn9jjq.narinfo20342026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (13.74ms)20352026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000020362026/09/23 09:41:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures20372026/09/23 09:41:00 INFO Garbage collection started20382026/09/23 09:41:00 OK 1_commit_pending_closure.sql (2.3ms)20392026/09/23 09:41:00 OK 2_object_stats_trigger.sql (1.36ms)20402026/09/23 09:41:00 goose: up to current file version: 220412026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures2042--- PASS: TestReadProxyInvalidPath (0.52s)2043=== CONT TestClientErrorHandling/InvalidAuthToken20442026/09/23 09:41:00 OK 20241026095416_initial_model.sql (9.06ms)20452026-09-23 09:41:00.101 UTC [1450] ERROR: relation "goose_db_version" does not exist at character 3620462026-09-23 09:41:00.101 UTC [1450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20472026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (2ms)20482026/09/23 09:41:00 INFO Aborted multipart uploads count=020492026/09/23 09:41:00 OK 20251218171726_add_pins.sql (2.79ms)20502026/09/23 09:41:00 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/09/23 09:41:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures20522026/09/23 09:41:00 INFO Garbage collection started20532026/09/23 09:41:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20542026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)20552026/09/23 09:41:00 OK 20260905000000_add_claims.sql (3.35ms)20562026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (2.6ms)20572026/09/23 09:41:00 goose: successfully migrated database to version: 202609200000002058=== CONT TestCacheConfigHandler/full_config,_no_issuer20592026/09/23 09:41:00 OK 20241026095416_initial_model.sql (8.3ms)2060=== CONT TestCacheConfigHandler/no_cache_url_configured2061=== CONT TestCacheConfigHandler/no_signing_keys2062=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2063--- PASS: TestCacheConfigHandler (0.00s)2064 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2065 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2066 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2067 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)20682026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)20692026/09/23 09:41:00 OK 1_commit_pending_closure.sql (1.66ms)20702026/09/23 09:41:00 INFO Aborted multipart uploads count=020712026/09/23 09:41:00 OK 2_object_stats_trigger.sql (1.11ms)20722026/09/23 09:41:00 goose: up to current file version: 220732026/09/23 09:41:00 OK 20251218171726_add_pins.sql (2.74ms)20742026/09/23 09:41:00 WARN Force mode enabled - objects will be deleted immediately without grace period20752026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)2076--- PASS: TestService_ReadAuthMiddleware (0.47s)20772026/09/23 09:41:00 OK 20260905000000_add_claims.sql (3.69ms)20782026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (2.69ms)20792026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000020802026/09/23 09:41:00 OK 1_commit_pending_closure.sql (2.37ms)20812026/09/23 09:41:00 OK 2_object_stats_trigger.sql (2.08ms)20822026/09/23 09:41:00 goose: up to current file version: 220832026/09/23 09:41:00 INFO Received uploads request method=POST path=/api/pending_closures20842026/09/23 09:41:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20852026/09/23 09:41:00 INFO Uploading bhsdxz98akj8as4xbm483al8bh23cv1q-ca-test (144B)20862026/09/23 09:41:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20872026/09/23 09:41:00 WARN Failed to register uploaded object key=log/6qlxsh65hql69713k0cp1vvix1mp1z7d-ca-test.drv error="server returned 404: 404 page not found\n"20882026/09/23 09:41:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20892026/09/23 09:41:00 WARN Failed to register uploaded object key=bhsdxz98akj8as4xbm483al8bh23cv1q.ls error="server returned 404: 404 page not found\n"20902026/09/23 09:41:00 INFO Signed narinfos id=1 count=120912026/09/23 09:41:00 INFO Uploading 1 narinfos20922026-09-23 09:41:00.162 UTC [1541] ERROR: relation "goose_db_version" does not exist at character 3620932026-09-23 09:41:00.162 UTC [1541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2094--- PASS: TestReadRedirectUsesPublicS3URL (0.49s)20952026/09/23 09:41:00 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20962026/09/23 09:41:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20972026/09/23 09:41:00 WARN Failed to register uploaded object key=bhsdxz98akj8as4xbm483al8bh23cv1q.narinfo error="server returned 404: 404 page not found\n"20982026/09/23 09:41:00 OK 20241026095416_initial_model.sql (7.29ms)20992026/09/23 09:41:00 INFO Completed upload id=121002026/09/23 09:41:00 INFO Upload complete. (106ms)21012026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)21022026/09/23 09:41:00 OK 20251218171726_add_pins.sql (2.3ms)2103=== NAME TestClientCADerivations2104 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1598149617/001/store/bhsdxz98akj8as4xbm483al8bh23cv1q-ca-test2105 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2106 Compression: zstd2107 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2108 NarSize: 1442109 References: 2110 Deriver: /build/TestClientCADerivations1598149617/001/store/6qlxsh65hql69713k0cp1vvix1mp1z7d-ca-test.drv2111 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2112 client_ca_test.go:185: Checking for realisation files in S3...21132026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (2.42ms)2114 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2115 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21162026-09-23 09:41:00.181 UTC [1542] ERROR: relation "goose_db_version" does not exist at character 3621172026-09-23 09:41:00.181 UTC [1542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21182026/09/23 09:41:00 OK 20260905000000_add_claims.sql (2.76ms)21192026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (1.67ms)21202026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000021212026/09/23 09:41:00 OK 1_commit_pending_closure.sql (1.32ms)21222026/09/23 09:41:00 OK 2_object_stats_trigger.sql (730.57µs)21232026/09/23 09:41:00 goose: up to current file version: 22124--- PASS: TestReadProxyRangeRequest (0.47s)21252026/09/23 09:41:00 OK 20241026095416_initial_model.sql (6.61ms)21262026/09/23 09:41:00 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)21272026/09/23 09:41:00 OK 20251218171726_add_pins.sql (2.36ms)21282026/09/23 09:41:00 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)21292026/09/23 09:41:00 OK 20260905000000_add_claims.sql (2.51ms)21302026/09/23 09:41:00 OK 20260920000000_drop_claims.sql (1.54ms)21312026/09/23 09:41:00 goose: successfully migrated database to version: 2026092000000021322026/09/23 09:41:00 OK 1_commit_pending_closure.sql (3ms)21332026/09/23 09:41:00 OK 2_object_stats_trigger.sql (705.89µs)21342026/09/23 09:41:00 goose: up to current file version: 22135=== RUN TestService_RequireScope_OIDC/builder_may_write2136=== PAUSE TestService_RequireScope_OIDC/builder_may_write2137=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2138=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2139=== RUN TestService_RequireScope_OIDC/ops_may_admin2140=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2141=== RUN TestService_RequireScope_OIDC/ops_may_not_write2142=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2143=== RUN TestService_RequireScope_OIDC/reader_may_not_write2144=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2145=== RUN TestService_RequireScope_OIDC/static_token_may_admin2146=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2147=== RUN TestService_RequireScope_OIDC/static_token_may_write2148=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2149=== RUN TestService_RequireScope_OIDC/reader_may_read2150=== PAUSE TestService_RequireScope_OIDC/reader_may_read2151=== RUN TestService_RequireScope_OIDC/writer_implies_read2152=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2153=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2154=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2155=== CONT TestService_RequireScope_OIDC/builder_may_write2156=== CONT TestService_RequireScope_OIDC/reader_may_read2157=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2158=== CONT TestService_RequireScope_OIDC/static_token_may_write2159=== CONT TestService_RequireScope_OIDC/ops_may_admin2160=== CONT TestService_RequireScope_OIDC/static_token_may_admin2161=== CONT TestService_RequireScope_OIDC/ops_may_not_write2162=== CONT TestService_RequireScope_OIDC/writer_implies_read2163=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2164=== CONT TestService_RequireScope_OIDC/reader_may_not_write2165--- PASS: TestService_RequireScope_OIDC (0.54s)2166 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2167 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2168 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2169 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2170 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2171 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2172 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2173 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2174 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2175 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2176--- PASS: TestReadRedirectNar (0.40s)21772026/09/23 09:41:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.241669ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2178--- PASS: TestReadProxyDisabled (0.41s)2179--- PASS: TestReadRedirectKeepsNarinfoProxied (0.46s)2180=== NAME TestClientCADerivations2181 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2182 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2183 error: binary cache 's3://bucket36?endpoint=http://localhost:35013®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1598149617/001/store'2184 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12185--- PASS: TestClientCADerivations (0.97s)2186=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2187=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2188=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2189=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2190=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2191=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2192=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2193=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2194=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2195=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2196=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21972026/09/23 09:41:00 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]2198=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21992026/09/23 09:41:00 WARN Authentication failed token_preview=eyJhbGciOi...8tRWIkgArA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2200--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2201 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2202 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2203 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2204 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2205--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.43s)2206--- PASS: TestReadProxyNarStreaming (0.45s)2207--- PASS: TestReadProxyNarinfo (0.46s)22082026/09/23 09:41:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22092026/09/23 09:41:00 WARN mTLS auth: bound subjects configured but subject DN unavailable22102026/09/23 09:41:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2211--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.46s)2212--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.46s)22132026/09/23 09:41:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.394066ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2214--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2215 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2216 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2217 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.58s)22182026/09/23 09:41:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22192026/09/23 09:41:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22202026/09/23 09:41:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22212026/09/23 09:41:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22222026/09/23 09:41:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTNmYThjNDEtNjU1ZS00ZDI4LWI3OTAtNjkxYjY1MTgzZDIzLjhmNzE2N2IzLWUxZjktNDRiYS04ZTM2LWNhMTlmNmUxZTJkOXgxNzkwMTU2NDYwMDkyNDI4MjY1 parts=122223--- PASS: TestRedundantMultipartUpload (1.17s)22242026/09/23 09:41:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.633458ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2225=== NAME TestOrphanedObjectsGCStressTest2226 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2227 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22282026/09/23 09:41:01 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=022292026/09/23 09:41:01 INFO Vacuumed table table=pending_closures22302026/09/23 09:41:01 INFO Vacuumed table table=pending_objects22312026/09/23 09:41:01 INFO Vacuumed table table=multipart_uploads22322026/09/23 09:41:01 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=022332026/09/23 09:41:01 INFO Vacuumed table table=closures22342026/09/23 09:41:01 INFO Vacuumed table table=objects22352026/09/23 09:41:01 INFO Vacuumed table table=pending_closures22362026/09/23 09:41:01 INFO Vacuumed table table=pending_objects22372026/09/23 09:41:01 INFO Vacuumed table table=multipart_uploads22382026/09/23 09:41:01 INFO Vacuumed table table=closures22392026/09/23 09:41:01 INFO Vacuumed table table=objects2240 orphaned_objects_gc_test.go:509: Stress test completed successfully:2241 orphaned_objects_gc_test.go:510: - Active objects preserved: 202242 orphaned_objects_gc_test.go:511: - Objects deleted: 2102243 orphaned_objects_gc_test.go:512: - Total GC'd: 2102244--- PASS: TestOrphanedObjectsGCStressTest (2.69s)22452026/09/23 09:41:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.725645072s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22462026/09/23 09:41:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02247=== NAME TestPinProtectsFromGC2248 client_integration_test.go:794: Pin successfully protected closure from garbage collection2249--- PASS: TestPinProtectsFromGC (2.94s)22502026/09/23 09:41:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02251=== NAME TestClientIntegration2252 client_integration_test.go:323: Objects in database after GC:2253 client_integration_test.go:323: Successfully deleted all objects with GC --force2254--- PASS: TestClientIntegration (2.78s)22552026/09/23 09:41:03 WARN Rate limiter enabled after throttle name=s3-test rate=522562026/09/23 09:41:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2257=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2258 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102259 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002260--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.64s)22612026/09/23 09:41:03 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-config22622026/09/23 09:41:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.685071ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22632026/09/23 09:41:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=375.314805ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22642026/09/23 09:41:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=787.418204ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22652026/09/23 09:41:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.476400774s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22662026/09/23 09:41:06 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"22672026/09/23 09:41:06 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_closures22682026/09/23 09:41:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.527464ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22692026/09/23 09:41:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.42291ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22702026/09/23 09:41:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=810.534695ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22712026/09/23 09:41:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.669585497s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2272--- PASS: TestClientErrorHandling (0.00s)2273 --- PASS: TestClientErrorHandling/InvalidStorePath (0.46s)2274 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.62s)2275 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.65s)2276PASS22772026-09-23 09:41:10.056 UTC [128] LOG: received smart shutdown request22782026-09-23 09:41:10.061 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 122792026-09-23 09:41:10.068 UTC [133] LOG: shutting down22802026-09-23 09:41:10.069 UTC [133] LOG: checkpoint starting: shutdown immediate22812026-09-23 09:41:10.699 UTC [133] LOG: checkpoint complete: wrote 10991 buffers (67.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.255 s, sync=0.342 s, total=0.631 s; sync files=19406, longest=0.077 s, average=0.001 s; distance=264839 kB, estimate=264839 kB; lsn=0/11A07C00, redo lsn=0/11A07C0022822026-09-23 09:41:10.774 UTC [128] LOG: database system is shut down2283Running OIDC tests...2284=== RUN TestAudienceForIssuer2285=== PAUSE TestAudienceForIssuer2286=== RUN TestGlobMatch2287=== PAUSE TestGlobMatch2288=== RUN TestValidateToken_ValidToken2289=== PAUSE TestValidateToken_ValidToken2290=== RUN TestValidateToken_WrongAudience2291=== PAUSE TestValidateToken_WrongAudience2292=== RUN TestValidateToken_Expired2293=== PAUSE TestValidateToken_Expired2294=== RUN TestValidateToken_BoundClaimsMismatch2295=== PAUSE TestValidateToken_BoundClaimsMismatch2296=== RUN TestValidateToken_BoundSubjectMismatch2297=== PAUSE TestValidateToken_BoundSubjectMismatch2298=== RUN TestValidateToken_MultipleProviders2299=== PAUSE TestValidateToken_MultipleProviders2300=== RUN TestValidateToken_NoMatchingProvider2301=== PAUSE TestValidateToken_NoMatchingProvider2302=== RUN TestValidateToken_KubernetesServiceAccount2303=== PAUSE TestValidateToken_KubernetesServiceAccount2304=== RUN TestNewValidator_KubernetesRequiresCA2305=== PAUSE TestNewValidator_KubernetesRequiresCA2306=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2307=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2308=== RUN TestPins_ReservedForMatchingRule2309=== PAUSE TestPins_ReservedForMatchingRule2310=== RUN TestPins_TopLevelShorthand2311=== PAUSE TestPins_TopLevelShorthand2312=== RUN TestPins_ConfigValidation2313=== PAUSE TestPins_ConfigValidation2314=== RUN TestScopes_LegacyProviderDefaultsToWrite2315=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2316=== RUN TestScopes_Rules2317=== PAUSE TestScopes_Rules2318=== RUN TestScopes_ConfigValidation2319=== PAUSE TestScopes_ConfigValidation2320=== CONT TestAudienceForIssuer2321=== CONT TestValidateToken_BoundClaimsMismatch2322=== CONT TestPins_ConfigValidation2323--- PASS: TestAudienceForIssuer (0.00s)2324=== CONT TestValidateToken_KubernetesServiceAccount2325=== CONT TestValidateToken_Expired2326=== CONT TestValidateToken_WrongAudience2327=== CONT TestValidateToken_ValidToken2328=== CONT TestPins_TopLevelShorthand2329--- PASS: TestPins_ConfigValidation (0.00s)2330=== CONT TestPins_ReservedForMatchingRule2331=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2332=== CONT TestGlobMatch2333=== RUN TestGlobMatch/foo_foo2334=== PAUSE TestGlobMatch/foo_foo2335=== RUN TestGlobMatch/foo_bar2336=== PAUSE TestGlobMatch/foo_bar2337=== RUN TestGlobMatch/*_2338=== PAUSE TestGlobMatch/*_2339=== RUN TestGlobMatch/*_anything2340=== PAUSE TestGlobMatch/*_anything2341=== RUN TestGlobMatch/foo*_foo2342=== PAUSE TestGlobMatch/foo*_foo2343=== RUN TestGlobMatch/foo*_foobar2344=== PAUSE TestGlobMatch/foo*_foobar2345=== RUN TestGlobMatch/foo*_bar2346=== PAUSE TestGlobMatch/foo*_bar2347=== RUN TestGlobMatch/*bar_bar2348=== CONT TestValidateToken_MultipleProviders2349=== CONT TestNewValidator_KubernetesRequiresCA2350=== CONT TestValidateToken_NoMatchingProvider2351=== CONT TestScopes_Rules2352=== CONT TestScopes_ConfigValidation2353=== CONT TestValidateToken_BoundSubjectMismatch2354=== CONT TestScopes_LegacyProviderDefaultsToWrite2355=== PAUSE TestGlobMatch/*bar_bar2356--- PASS: TestScopes_ConfigValidation (0.00s)2357=== RUN TestGlobMatch/*bar_foobar2358=== PAUSE TestGlobMatch/*bar_foobar2359=== RUN TestGlobMatch/*bar_foo2360=== PAUSE TestGlobMatch/*bar_foo2361=== RUN TestGlobMatch/foo*bar_foobar2362=== PAUSE TestGlobMatch/foo*bar_foobar2363=== RUN TestGlobMatch/foo*bar_foo123bar2364=== PAUSE TestGlobMatch/foo*bar_foo123bar2365=== RUN TestGlobMatch/foo*bar_foobarbaz2366=== PAUSE TestGlobMatch/foo*bar_foobarbaz2367=== RUN TestGlobMatch/*/*_foo/bar2368=== PAUSE TestGlobMatch/*/*_foo/bar2369=== RUN TestGlobMatch/*/*_foo2370=== PAUSE TestGlobMatch/*/*_foo2371=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2372=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2373=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02374=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02375=== RUN TestGlobMatch/refs/*/main_refs/heads/main2376=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2377=== RUN TestGlobMatch/fo?_foo2378=== PAUSE TestGlobMatch/fo?_foo2379=== RUN TestGlobMatch/fo?_fo2380=== PAUSE TestGlobMatch/fo?_fo2381=== RUN TestGlobMatch/fo?_fooo2382=== PAUSE TestGlobMatch/fo?_fooo2383=== RUN TestGlobMatch/?oo_foo2384=== PAUSE TestGlobMatch/?oo_foo2385=== RUN TestGlobMatch/?oo_boo2386=== PAUSE TestGlobMatch/?oo_boo2387=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2388=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2389=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2390=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2391=== CONT TestGlobMatch/foo_foo2392=== CONT TestGlobMatch/*/*_foo2393=== CONT TestGlobMatch/*/*_foo/bar2394=== CONT TestGlobMatch/foo*bar_foobarbaz2395=== CONT TestGlobMatch/foo*bar_foo123bar2396=== CONT TestGlobMatch/foo*bar_foobar2397=== CONT TestGlobMatch/fo?_foo2398=== CONT TestGlobMatch/*bar_bar2399=== CONT TestGlobMatch/foo*_bar2400=== CONT TestGlobMatch/foo*_foobar2401=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2402=== CONT TestGlobMatch/refs/*/main_refs/heads/main2403=== CONT TestGlobMatch/fo?_fo2404=== CONT TestGlobMatch/fo?_fooo2405=== CONT TestGlobMatch/foo_bar2406=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02407=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2408=== CONT TestGlobMatch/?oo_boo2409=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2410=== CONT TestGlobMatch/*bar_foo2411=== CONT TestGlobMatch/*bar_foobar2412=== CONT TestGlobMatch/?oo_foo2413=== CONT TestGlobMatch/foo*_foo2414=== CONT TestGlobMatch/*_anything2415=== CONT TestGlobMatch/*_2416--- PASS: TestGlobMatch (0.01s)2417 --- PASS: TestGlobMatch/foo_foo (0.00s)2418 --- PASS: TestGlobMatch/*/*_foo (0.00s)2419 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2420 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2421 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2422 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2423 --- PASS: TestGlobMatch/fo?_foo (0.00s)2424 --- PASS: TestGlobMatch/*bar_bar (0.00s)2425 --- PASS: TestGlobMatch/foo*_bar (0.00s)2426 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2427 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2428 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2429 --- PASS: TestGlobMatch/fo?_fo (0.00s)2430 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2431 --- PASS: TestGlobMatch/foo_bar (0.00s)2432 --- PASS: TestGlobMatch/?oo_boo (0.00s)2433 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2434 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2435 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2436 --- PASS: TestGlobMatch/*bar_foo (0.00s)2437 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2438 --- PASS: TestGlobMatch/?oo_foo (0.00s)2439 --- PASS: TestGlobMatch/foo*_foo (0.00s)2440 --- PASS: TestGlobMatch/*_anything (0.00s)2441 --- PASS: TestGlobMatch/*_ (0.00s)24422026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41939/oidc2443--- PASS: TestValidateToken_WrongAudience (0.03s)24442026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36287/oidc2445--- PASS: TestValidateToken_ValidToken (0.03s)24462026/09/23 09:41:12 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232447--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)24482026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41651/oidc2449--- PASS: TestScopes_Rules (0.05s)24502026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39583/oidc24512026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36223/oidc2452--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2453--- PASS: TestValidateToken_Expired (0.06s)24542026/09/23 09:41:12 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4529124552026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46841/oidc24562026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34601/oidc2457--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2458--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)2459--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)24602026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44529/oidc2461--- PASS: TestPins_ReservedForMatchingRule (0.09s)24622026/09/23 09:41:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43599/oidc24632026/09/23 09:41:12 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44177/oidc2464--- PASS: TestValidateToken_MultipleProviders (0.11s)24652026/09/23 09:41:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34969/oidc2466--- PASS: TestValidateToken_NoMatchingProvider (0.12s)24672026/09/23 09:41:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43631/oidc2468--- PASS: TestPins_TopLevelShorthand (0.13s)24692026/09/23 09:41:12 http: TLS handshake error from 127.0.0.1:51884: remote error: tls: bad certificate2470--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)2471PASS2472Running hook tests...2473=== RUN TestSendPathsEmpty2474=== PAUSE TestSendPathsEmpty2475=== RUN TestQueueEnqueueAndFetch2476=== PAUSE TestQueueEnqueueAndFetch2477=== RUN TestQueueDeduplication2478=== PAUSE TestQueueDeduplication2479=== RUN TestQueueRemove2480=== PAUSE TestQueueRemove2481=== RUN TestQueueFetchBatchLimit2482=== PAUSE TestQueueFetchBatchLimit2483=== RUN TestQueueRetryMovesToBack2484=== PAUSE TestQueueRetryMovesToBack2485=== RUN TestQueueFetchRemoveLifecycle2486=== PAUSE TestQueueFetchRemoveLifecycle2487=== RUN TestQueueConcurrentWriters2488=== PAUSE TestQueueConcurrentWriters2489=== RUN TestQueueRemoveLargeClosure2490=== PAUSE TestQueueRemoveLargeClosure2491=== RUN TestServerClientIntegration2492=== PAUSE TestServerClientIntegration2493=== RUN TestServerQueueError2494=== PAUSE TestServerQueueError2495=== RUN TestGetListenerSocketActivation2496 server_test.go:210: === RUN TestGetListenerSocketActivation2497 --- PASS: TestGetListenerSocketActivation (0.00s)2498 PASS2499 2500--- PASS: TestGetListenerSocketActivation (0.01s)2501=== RUN TestDrainIsolatesPoisonPath2502=== PAUSE TestDrainIsolatesPoisonPath2503=== RUN TestRunNotBlockedByPoisonHead2504=== PAUSE TestRunNotBlockedByPoisonHead2505=== RUN TestDrainGivesUpWhenServerDown2506=== PAUSE TestDrainGivesUpWhenServerDown2507=== RUN TestFailedPathPrunedByLaterClosure2508=== PAUSE TestFailedPathPrunedByLaterClosure2509=== RUN TestWorkerUploadsAndRemoves2510=== PAUSE TestWorkerUploadsAndRemoves2511=== RUN TestWorkerSkipsGCdPaths2512=== PAUSE TestWorkerSkipsGCdPaths2513=== RUN TestWorkerPrunesClosureDeps2514=== PAUSE TestWorkerPrunesClosureDeps2515=== RUN TestDrainTimeout2516=== PAUSE TestDrainTimeout2517=== CONT TestSendPathsEmpty2518=== CONT TestServerQueueError2519--- PASS: TestSendPathsEmpty (0.00s)2520=== CONT TestServerClientIntegration2521=== CONT TestQueueRemoveLargeClosure2522=== CONT TestQueueConcurrentWriters2523=== CONT TestQueueFetchRemoveLifecycle25242026/09/23 09:41:12 ERROR Failed to queue paths error="permission denied" count=12525=== CONT TestQueueRetryMovesToBack2526=== CONT TestQueueFetchBatchLimit2527=== CONT TestQueueRemove2528--- PASS: TestServerClientIntegration (0.00s)2529=== CONT TestQueueDeduplication2530=== CONT TestQueueEnqueueAndFetch2531=== CONT TestDrainGivesUpWhenServerDown2532=== CONT TestFailedPathPrunedByLaterClosure2533=== CONT TestWorkerUploadsAndRemoves2534=== CONT TestRunNotBlockedByPoisonHead2535=== CONT TestDrainTimeout2536=== CONT TestWorkerPrunesClosureDeps2537=== CONT TestDrainIsolatesPoisonPath2538=== CONT TestWorkerSkipsGCdPaths2539--- PASS: TestServerQueueError (0.00s)25402026/09/23 09:41:12 INFO Upload queue status pending=22541--- PASS: TestQueueDeduplication (0.01s)25422026/09/23 09:41:12 INFO Uploading batch count=425432026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=425442026/09/23 09:41:12 INFO Uploading batch count=225452026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=225462026/09/23 09:41:12 INFO Uploading batch count=125472026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3668471951/002/a2548--- PASS: TestQueueFetchBatchLimit (0.02s)25492026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath162838943/002/bbb2550--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25512026/09/23 09:41:12 INFO Upload queue status pending=225522026/09/23 09:41:12 INFO Uploading batch count=125532026/09/23 09:41:12 INFO Uploading batch count=225542026/09/23 09:41:12 INFO Upload queue status pending=225552026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=12556--- PASS: TestQueueRemove (0.02s)25572026/09/23 09:41:12 INFO Uploading batch count=22558--- PASS: TestQueueRetryMovesToBack (0.02s)25592026/09/23 09:41:12 INFO Upload queue status pending=325602026/09/23 09:41:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3665031247/002/nonexistent25612026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3668471951/002/b25622026/09/23 09:41:12 INFO Uploading batch count=125632026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=12564--- PASS: TestQueueEnqueueAndFetch (0.02s)25652026/09/23 09:41:12 INFO Uploading batch count=125662026/09/23 09:41:12 INFO Uploading batch count=125672026/09/23 09:41:12 INFO Uploading batch count=125682026/09/23 09:41:12 INFO Uploading batch count=225692026/09/23 09:41:12 INFO Uploading batch count=125702026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=125712026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=225722026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3668471951/002/c25732026/09/23 09:41:12 INFO Uploading batch count=125742026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=125752026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3668471951/002/d25762026/09/23 09:41:12 INFO Uploading batch count=125772026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=125782026/09/23 09:41:12 ERROR Drain finished with paths left in queue remaining=12579--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25802026/09/23 09:41:12 INFO Uploading batch count=225812026/09/23 09:41:12 ERROR Upload failed error="upload failed" count=225822026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3668471951/002/e25832026/09/23 09:41:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3668471951/002/f25842026/09/23 09:41:12 ERROR Drain finished with paths left in queue remaining=102585--- PASS: TestDrainIsolatesPoisonPath (0.02s)2586--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2587--- PASS: TestWorkerPrunesClosureDeps (0.04s)2588--- PASS: TestWorkerSkipsGCdPaths (0.04s)2589--- PASS: TestWorkerUploadsAndRemoves (0.04s)2590--- PASS: TestQueueRemoveLargeClosure (0.08s)25912026/09/23 09:41:12 ERROR Upload failed error="context deadline exceeded" count=225922026/09/23 09:41:12 ERROR Drain finished with paths left in queue remaining=42593--- PASS: TestDrainTimeout (0.22s)2594--- PASS: TestQueueConcurrentWriters (0.28s)25952026/09/23 09:41:13 INFO Uploading batch count=125962026/09/23 09:41:13 INFO Uploading batch count=125972026/09/23 09:41:13 INFO Uploading batch count=125982026/09/23 09:41:13 ERROR Upload failed error="upload failed" count=125992026/09/23 09:41:13 INFO Uploading batch count=126002026/09/23 09:41:13 ERROR Upload failed error="upload failed" count=126012026/09/23 09:41:13 INFO Uploading batch count=126022026/09/23 09:41:13 ERROR Upload failed error="upload failed" count=126032026/09/23 09:41:13 INFO Uploading batch count=126042026/09/23 09:41:13 ERROR Upload failed error="upload failed" count=126052026/09/23 09:41:13 ERROR Drain finished with paths left in queue remaining=12606--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2607PASS