niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #276
· raw
1tribuchet: building on eliza2Running 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 TestScriptTokenEmptyCommand98--- PASS: TestScriptTokenEmptyCommand (0.00s)99=== CONT TestParsePathInfoJSONMultiplePaths100=== CONT TestSetClientTLSDoesNotMutateDefaultTransport101=== CONT TestScriptTokenBadJSON102=== CONT TestScriptTokenEmptyToken103=== CONT TestScriptTokenCachesUntilRefresh104=== CONT TestScriptTokenNoExpiryRerunsEveryCall105--- PASS: TestScriptTokenScriptFails (0.00s)106=== CONT TestResolveStorePath107=== CONT TestFileTokenEmpty108=== CONT TestFileTokenMissing109=== CONT TestFileTokenReadsAndCaches110=== CONT TestStaticToken111=== CONT TestSetClientTLSErrors112=== CONT TestClientSignaturesByStorePath113=== CONT TestPathInfoCACompatibility114=== RUN TestPathInfoCACompatibility/null_ca_field115=== CONT TestRateLimiterFeedback116=== RUN TestRateLimiterFeedback/429_enables_limiter117=== PAUSE TestRateLimiterFeedback/429_enables_limiter118=== CONT TestStreamPushReportsEveryPath119=== CONT TestStreamPushIsolatesFailures120=== CONT TestDoWithRetry_BodyReplayedViaGetBody121=== CONT TestStreamPushBatchesUnderLoad122=== CONT TestShellSplitErrors123=== CONT TestShellSplit124=== CONT TestStreamPushReportsSignatures125=== CONT TestStreamPushRequestLine126=== CONT TestStreamPushGivesUpOnDeadServer127=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths128--- PASS: TestStaticToken (0.00s)129=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess130=== CONT TestSetClientTLS131=== PAUSE TestPathInfoCACompatibility/null_ca_field132=== RUN TestRateLimiterFeedback/503_enables_limiter133=== CONT TestPathInfoHashCompatibility134=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)135--- PASS: TestScriptTokenBadJSON (0.00s)136--- PASS: TestClientSignaturesByStorePath (0.00s)137--- PASS: TestFileTokenEmpty (0.00s)138--- PASS: TestShellSplitErrors (0.00s)139--- PASS: TestShellSplit (0.00s)140=== CONT TestParsePathInfoJSON141--- PASS: TestFileTokenMissing (0.00s)142=== RUN TestParsePathInfoJSON/Nix_format143=== PAUSE TestParsePathInfoJSON/Nix_format144=== CONT TestGetStorePathHash145--- PASS: TestFileTokenReadsAndCaches (0.00s)146=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths147=== CONT TestConvertHashToNix32148=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths149=== RUN TestConvertHashToNix32/SRI_format_to_Nix32150=== CONT TestUploadMultipart_SupersededByPeer151=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix321522026/09/29 08:15:42 ERROR Upload failed error="connection refused" count=20153=== RUN TestConvertHashToNix32/already_Nix32_format1542026/09/29 08:15:42 ERROR Server seems unavailable, giving up on batch untried=17155=== PAUSE TestConvertHashToNix32/already_Nix32_format156=== RUN TestParsePathInfoJSON/Lix_format1572026/09/29 08:15:42 ERROR Upload failed error="bad path" count=3158=== PAUSE TestParsePathInfoJSON/Lix_format1592026/09/29 08:15:42 WARN Rate limiter enabled after throttle name=server-test rate=51602026/09/29 08:15:42 ERROR Upload failed error=boom count=1161=== RUN TestParsePathInfoJSON/empty_input162=== RUN TestPathInfoCACompatibility/old_string_format_-_text163=== PAUSE TestParsePathInfoJSON/empty_input1642026/09/29 08:15:42 ERROR Upload failed error=boom count=1165=== CONT TestFilterOversizedClosures166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text167=== RUN TestFilterOversizedClosures/no_limit_keeps_everything168=== RUN TestConvertHashToNix32/invalid_format169=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive170=== PAUSE TestConvertHashToNix32/invalid_format1712026/09/29 08:15:42 WARN Rate limiter enabled after throttle name=server-test rate=5172=== CONT TestRegisterUploadedObjectReusesConnections1732026/09/29 08:15:42 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44441174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon177=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI179=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121802026/09/29 08:15:42 WARN Rate limiter backed off name=server-test rate=51812026/09/29 08:15:42 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44441182=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive183--- PASS: TestScriptTokenEmptyToken (0.00s)184--- PASS: TestDoServerRequestAttachesToken (0.01s)185=== CONT TestDumpPathSingleFile186--- PASS: TestResolveStorePath (0.00s)187=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths188=== RUN TestUploadMultipart_SupersededByPeer/exists189=== RUN TestGetStorePathHash/valid_store_path190=== CONT TestDumpPathWriterError191=== CONT TestPartSizeForNAR192=== PAUSE TestRateLimiterFeedback/503_enables_limiter193=== CONT TestDumpPathMatchesNix194=== CONT TestUploadMultipart_PartsInParallel195=== RUN TestParsePathInfoJSON/whitespace_only196=== CONT TestCaseHackSuffix197=== RUN TestSetClientTLSErrors/missing_cert_file198=== CONT TestEncodeNixBase32199=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything200=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== RUN TestPathInfoCACompatibility/new_structured_format_-_text202=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text203=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method204=== RUN TestPartSizeForNAR/zero_stays_at_minimum205=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method206--- PASS: TestStreamPushReportsEveryPath (0.00s)207=== PAUSE TestGetStorePathHash/valid_store_path208=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum209=== CONT TestConvertHashToNix32/SRI_format_to_Nix32210=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped211=== RUN TestPartSizeForNAR/small_stays_at_minimum212=== CONT TestEncodeNixBase32WithRealHash213=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter214=== PAUSE TestUploadMultipart_SupersededByPeer/exists215=== RUN TestUploadMultipart_SupersededByPeer/missing216=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths217=== PAUSE TestPartSizeForNAR/small_stays_at_minimum218=== CONT TestPathInfoCACompatibility/null_ca_field219=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum220=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths221=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method222=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512224=== RUN TestGetStorePathHash/basename_without_hyphen_should_error225=== RUN TestEncodeNixBase32/test_string_hash226=== PAUSE TestSetClientTLSErrors/missing_cert_file227=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped228=== PAUSE TestParsePathInfoJSON/whitespace_only229=== CONT TestConvertHashToNix32/already_Nix32_format230=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter231--- PASS: TestStreamPushIsolatesFailures (0.00s)232=== PAUSE TestUploadMultipart_SupersededByPeer/missing233=== CONT TestPathInfoCACompatibility/new_structured_format_-_text234=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter235=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter236=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)237=== CONT TestRateLimiterFeedback/429_enables_limiter238=== CONT TestUploadMultipart_SupersededByPeer/exists239=== CONT TestUploadMultipart_SupersededByPeer/missing240=== CONT TestPathInfoCACompatibility/old_string_format_-_text241=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum242=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts243=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts244=== RUN TestPartSizeForNAR/1_TiB245=== PAUSE TestPartSizeForNAR/1_TiB246=== RUN TestPartSizeForNAR/5_TiB_S3_max_object247=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object248=== RUN TestPartSizeForNAR/capped_at_5_GiB249=== PAUSE TestPartSizeForNAR/capped_at_5_GiB250=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI251=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error2522026/09/29 08:15:42 WARN Rate limiter enabled after throttle name=server-test rate=5253=== RUN TestSetClientTLSErrors/missing_key_file2542026/09/29 08:15:42 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41497255=== PAUSE TestSetClientTLSErrors/missing_key_file256=== RUN TestFilterOversizedClosures/all_closures_skipped257=== PAUSE TestFilterOversizedClosures/all_closures_skipped258=== RUN TestParsePathInfoJSON/invalid_JSON259=== PAUSE TestParsePathInfoJSON/invalid_JSON2602026/09/29 08:15:42 WARN Rate limiter backed off name=server-test rate=5261=== CONT TestPartSizeForNAR/zero_stays_at_minimum262=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon263=== CONT TestPartSizeForNAR/1_TiB264=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts265--- PASS: TestStreamPushReportsSignatures (0.00s)266--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)267=== CONT TestConvertHashToNix32/invalid_format268=== PAUSE TestEncodeNixBase32/test_string_hash269=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter270=== CONT TestFilterOversizedClosures/no_limit_keeps_everything271=== CONT TestParsePathInfoJSON/Nix_format272=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped273=== CONT TestRateLimiterFeedback/503_enables_limiter2742026/09/29 08:15:42 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=2000275=== CONT TestParsePathInfoJSON/empty_input276=== CONT TestParsePathInfoJSON/Lix_format277=== RUN TestEncodeNixBase32/empty_input278=== RUN TestSetClientTLS/rejects_connection_without_client_cert279=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert280=== PAUSE TestEncodeNixBase32/empty_input281=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error282=== RUN TestSetClientTLSErrors/missing_ca_file283=== PAUSE TestSetClientTLSErrors/missing_ca_file284=== CONT TestPartSizeForNAR/capped_at_5_GiB285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== PAUSE TestSetClientTLSErrors/invalid_ca_file2872026/09/29 08:15:42 WARN Rate limiter enabled after throttle name=server-test rate=5288=== CONT TestSetClientTLSErrors/missing_cert_file2892026/09/29 08:15:42 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43079290=== CONT TestSetClientTLSErrors/missing_key_file291=== CONT TestPartSizeForNAR/5_TiB_S3_max_object292=== CONT TestSetClientTLSErrors/invalid_ca_file2932026/09/29 08:15:42 WARN Rate limiter backed off name=server-test rate=5294=== CONT TestPartSizeForNAR/small_stays_at_minimum295=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum296--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)297--- PASS: TestEncodeNixBase32WithRealHash (0.00s)298=== CONT TestFilterOversizedClosures/all_closures_skipped2992026/09/29 08:15:42 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50300=== CONT TestParsePathInfoJSON/invalid_JSON301=== CONT TestParsePathInfoJSON/whitespace_only302=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter303=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA304=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA305=== CONT TestEncodeNixBase32/test_string_hash306=== CONT TestEncodeNixBase32/empty_input307=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error308=== CONT TestSetClientTLSErrors/missing_ca_file309--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)310=== RUN TestSetClientTLS/preserves_debug_logging_transport311=== PAUSE TestSetClientTLS/preserves_debug_logging_transport312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error314=== CONT TestSetClientTLS/preserves_debug_logging_transport315=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error316=== CONT TestGetStorePathHash/valid_store_path317=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error318--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)319=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA320=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error321=== CONT TestGetStorePathHash/basename_without_hyphen_should_error322--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)323 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)324 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)325--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)326--- PASS: TestPathInfoCACompatibility (0.01s)327 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)328 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)329 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)330 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)331 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)332--- PASS: TestPathInfoHashCompatibility (0.00s)333 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)334 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)335 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)336 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)337--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)338 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)339 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)340--- PASS: TestConvertHashToNix32 (0.00s)341 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.03s)342 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)343 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)344--- PASS: TestEncodeNixBase32 (0.03s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346 --- PASS: TestEncodeNixBase32/empty_input (0.00s)347--- PASS: TestPartSizeForNAR (0.03s)348 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)349 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)350 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)351 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)352 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)353 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)355--- PASS: TestRateLimiterFeedback (0.04s)356 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)357 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)360--- PASS: TestParsePathInfoJSON (0.04s)361 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)362 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)363 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)364 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)365 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)366--- PASS: TestFilterOversizedClosures (0.03s)367 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)368 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)369 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)370--- PASS: TestGetStorePathHash (0.04s)371 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)372 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)373 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)374 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)375--- PASS: TestSetClientTLSErrors (0.04s)376 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)378 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3802026/09/29 08:15:42 http: TLS handshake error from 127.0.0.1:38788: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.04s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)385--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)386--- PASS: TestStreamPushRequestLine (0.06s)387--- PASS: TestDumpPathSingleFile (0.06s)388--- PASS: TestCaseHackSuffix (0.06s)389--- PASS: TestDumpPathWriterError (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres3579453230/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/postgres3579453230/data -l logfile start422423/build/postgres3579453230:5432 - no response4242026-09-29 08:15:44.766 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-29 08:15:44.766 UTC [129] LOG: listening on Unix socket "/build/postgres3579453230/.s.PGSQL.5432"4262026-09-29 08:15:44.771 UTC [136] LOG: database system was shut down at 2026-09-29 08:15:44 UTC4272026-09-29 08:15:44.775 UTC [129] LOG: database system is ready to accept connections428/build/postgres3579453230:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-09-29 08:15:45.152 UTC [374] ERROR: relation "goose_db_version" does not exist at character 364712026-09-29 08:15:45.152 UTC [374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/09/29 08:15:45 OK 20241026095416_initial_model.sql (8.93ms)4732026/09/29 08:15:45 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)4742026/09/29 08:15:45 OK 20251218171726_add_pins.sql (2.98ms)4752026/09/29 08:15:45 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)4762026/09/29 08:15:45 OK 20260905000000_add_claims.sql (3.18ms)4772026/09/29 08:15:45 OK 20260920000000_drop_claims.sql (1.8ms)4782026/09/29 08:15:45 OK 20260923120000_add_pushes.sql (1.72ms)4792026/09/29 08:15:45 goose: successfully migrated database to version: 202609231200004802026/09/29 08:15:45 OK 1_commit_pending_closure.sql (1.83ms)4812026/09/29 08:15:45 OK 2_object_stats_trigger.sql (802.43µs)4822026/09/29 08:15:45 OK 3_commit_push.sql (645.75µs)4832026/09/29 08:15:45 goose: up to current file version: 34842026/09/29 08:15:45 INFO lead: acquired remote=192.0.2.1:12344852026/09/29 08:15:45 INFO lead: released remote=192.0.2.1:12344862026/09/29 08:15:45 INFO lead: acquired remote=192.0.2.1:12344872026/09/29 08:15:45 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-09-29 08:15:45.939 UTC [383] ERROR: relation "goose_db_version" does not exist at character 364932026-09-29 08:15:45.939 UTC [383] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/09/29 08:15:45 OK 20241026095416_initial_model.sql (10.49ms)4952026/09/29 08:15:45 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)4962026/09/29 08:15:45 OK 20251218171726_add_pins.sql (3.98ms)4972026/09/29 08:15:45 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)4982026/09/29 08:15:45 OK 20260905000000_add_claims.sql (7.14ms)4992026/09/29 08:15:45 OK 20260920000000_drop_claims.sql (2.52ms)5002026/09/29 08:15:45 OK 20260923120000_add_pushes.sql (2.81ms)5012026/09/29 08:15:45 goose: successfully migrated database to version: 202609231200005022026/09/29 08:15:45 OK 1_commit_pending_closure.sql (3.01ms)5032026/09/29 08:15:45 OK 2_object_stats_trigger.sql (8.09ms)5042026/09/29 08:15:45 OK 3_commit_push.sql (1.34ms)5052026/09/29 08:15:45 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestGCTaskStore_StartNew512=== PAUSE TestGCTaskStore_StartNew513=== RUN TestGCTaskStore_DeduplicateSameParams514=== PAUSE TestGCTaskStore_DeduplicateSameParams515=== RUN TestGCTaskStore_ConflictDifferentParams516=== PAUSE TestGCTaskStore_ConflictDifferentParams517=== RUN TestGCTaskStore_GetEmpty518=== PAUSE TestGCTaskStore_GetEmpty519=== RUN TestGCTaskStore_GetReturnsLatest520=== PAUSE TestGCTaskStore_GetReturnsLatest521=== RUN TestGCTaskStore_CompletedAllowsNewTask522=== PAUSE TestGCTaskStore_CompletedAllowsNewTask523=== RUN TestGCTaskStore_PhaseUpdates524=== PAUSE TestGCTaskStore_PhaseUpdates525=== RUN TestGCTaskStore_Fail526=== PAUSE TestGCTaskStore_Fail527=== RUN TestGracefulShutdownDrainsInflight528=== PAUSE TestGracefulShutdownDrainsInflight529=== RUN TestService_healthCheckHandler530=== PAUSE TestService_healthCheckHandler531=== RUN TestService_readinessHandler532=== PAUSE TestService_readinessHandler533=== RUN TestGenerateLandingPage534=== PAUSE TestGenerateLandingPage535=== RUN TestCacheConfigHandlerMaxNarSize536=== PAUSE TestCacheConfigHandlerMaxNarSize537=== RUN TestCreatePendingClosureRejectsOversizedNAR538=== PAUSE TestCreatePendingClosureRejectsOversizedNAR539=== RUN TestNARDeduplicationMetadataUploadBug540=== PAUSE TestNARDeduplicationMetadataUploadBug541=== RUN TestMetricsInventory542=== PAUSE TestMetricsInventory543=== RUN TestService_NativeMTLS544=== PAUSE TestService_NativeMTLS545=== RUN TestServerTLSConfig546=== PAUSE TestServerTLSConfig547=== RUN TestMultipartCleanup548=== PAUSE TestMultipartCleanup549=== RUN TestObjectStatsTrigger550=== PAUSE TestObjectStatsTrigger551=== RUN TestOrphanedObjectsGC552=== PAUSE TestOrphanedObjectsGC553=== RUN TestOrphanedObjectsGCStressTest554=== PAUSE TestOrphanedObjectsGCStressTest555=== RUN TestResurrectedObjectNotDeleted556=== PAUSE TestResurrectedObjectNotDeleted557=== RUN TestCreatePin_ReservedPins558=== PAUSE TestCreatePin_ReservedPins559=== RUN TestParseSingleRange560=== PAUSE TestParseSingleRange561=== RUN TestProxyHeadersOnlyTrustedOnSocket562=== PAUSE TestProxyHeadersOnlyTrustedOnSocket563=== RUN TestIsValidCachePath564=== PAUSE TestIsValidCachePath565=== RUN TestReadProxyNarinfo566=== PAUSE TestReadProxyNarinfo567=== RUN TestReadProxyNarinfoAlreadyDecompressed568=== PAUSE TestReadProxyNarinfoAlreadyDecompressed569=== RUN TestReadProxyNarStreaming570=== PAUSE TestReadProxyNarStreaming571=== RUN TestReadProxy404572=== PAUSE TestReadProxy404573=== RUN TestReadProxyInvalidPath574=== PAUSE TestReadProxyInvalidPath575=== RUN TestReadProxyHead576=== PAUSE TestReadProxyHead577=== RUN TestReadProxyConditionalGet578=== PAUSE TestReadProxyConditionalGet579=== RUN TestReadProxyRootRedirectsToIndexHTML580=== PAUSE TestReadProxyRootRedirectsToIndexHTML581=== RUN TestReadProxyDisabled582=== PAUSE TestReadProxyDisabled583=== RUN TestReadRedirectNar584=== PAUSE TestReadRedirectNar585=== RUN TestReadRedirectKeepsNarinfoProxied586=== PAUSE TestReadRedirectKeepsNarinfoProxied587=== RUN TestReadProxyRangeRequest588=== PAUSE TestReadProxyRangeRequest589=== RUN TestReadRedirectUsesPublicS3URL590=== PAUSE TestReadRedirectUsesPublicS3URL591=== RUN TestPush_OverlappingRootsStoreOneRowPerKey592=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey593=== RUN TestPush_CompleteCommitsEveryRoot594=== PAUSE TestPush_CompleteCommitsEveryRoot595=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected596=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected597=== RUN TestPush_RejectsBadRequests598=== PAUSE TestPush_RejectsBadRequests599=== RUN TestPush_SignsNarinfosOfItsPendingObjects600=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects601=== RUN TestRedundantMultipartUpload602=== PAUSE TestRedundantMultipartUpload603=== RUN TestCompleteMultipartUpload_ErrorButObjectExists604=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists605=== RUN TestCompletedNarNotReofferedAcrossClosures606=== PAUSE TestCompletedNarNotReofferedAcrossClosures607=== RUN TestPresignedUploadRegisteredBeforeCommit608=== PAUSE TestPresignedUploadRegisteredBeforeCommit609=== RUN TestService_Rustfstest610=== PAUSE TestService_Rustfstest611=== RUN TestParseSize612=== PAUSE TestParseSize613=== RUN TestSkippedUploadsHandler614=== PAUSE TestSkippedUploadsHandler615=== RUN TestSystemdListenerNotActivated616--- PASS: TestSystemdListenerNotActivated (0.00s)617=== RUN TestWatchdogBeatsWhenHealthy618--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)619=== RUN TestWatchdogSkipsWhenUnhealthy6202026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/29 08:15:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"630--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)631=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== RUN TestProxyWriteTimeout634=== PAUSE TestProxyWriteTimeout635=== RUN TestIsValidUploadKey636=== PAUSE TestIsValidUploadKey637=== RUN TestUploadHandlersRejectInvalidKeys638=== PAUSE TestUploadHandlersRejectInvalidKeys639=== RUN TestUploadHandlersRejectOversizedBody640=== PAUSE TestUploadHandlersRejectOversizedBody641=== RUN TestService_cleanupPendingClosuresHandler642=== PAUSE TestService_cleanupPendingClosuresHandler643=== RUN TestService_createPendingClosureHandler644=== PAUSE TestService_createPendingClosureHandler645=== RUN TestService_verifyS3Integrity646=== PAUSE TestService_verifyS3Integrity647=== RUN TestCompleteMultipartUnregistered648=== PAUSE TestCompleteMultipartUnregistered649=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT650=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT651=== CONT TestService_AuthMiddleware652=== CONT TestOrphanedObjectsGC653=== CONT TestPush_CompleteCommitsEveryRoot654=== CONT TestGCMetrics655=== CONT TestObjectStatsTrigger656=== CONT TestMultipartCleanup657=== CONT TestServerTLSConfig658=== RUN TestServerTLSConfig/no_client_CA659=== PAUSE TestServerTLSConfig/no_client_CA660=== RUN TestServerTLSConfig/missing_CA_file661=== PAUSE TestServerTLSConfig/missing_CA_file662=== RUN TestServerTLSConfig/not_a_PEM_file663=== PAUSE TestServerTLSConfig/not_a_PEM_file664=== CONT TestService_NativeMTLS665=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== CONT TestMetricsInventory667=== CONT TestNARDeduplicationMetadataUploadBug668=== CONT TestCreatePendingClosureRejectsOversizedNAR669=== CONT TestCacheConfigHandlerMaxNarSize670=== CONT TestGenerateLandingPage6712026/09/29 08:15:46 INFO Received uploads request method=POST path=/api/pending_closures672--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)673=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT674=== CONT TestService_readinessHandler675=== CONT TestService_healthCheckHandler676=== CONT TestGracefulShutdownDrainsInflight677=== CONT TestGCTaskStore_Fail678=== CONT TestService_verifyS3Integrity6792026/09/29 08:15:46 INFO Starting HTTP server address=127.0.0.1:45591680=== CONT TestGCTaskStore_PhaseUpdates681=== CONT TestService_createPendingClosureHandler682=== CONT TestGCTaskStore_CompletedAllowsNewTask683=== CONT TestService_cleanupPendingClosuresHandler684=== CONT TestGCTaskStore_GetReturnsLatest685=== CONT TestUploadHandlersRejectOversizedBody686=== CONT TestGCTaskStore_GetEmpty687=== CONT TestUploadHandlersRejectInvalidKeys688=== CONT TestGCTaskStore_ConflictDifferentParams689=== CONT TestGCTaskStore_DeduplicateSameParams690=== CONT TestGCTaskStore_StartNew691--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)692=== CONT TestCompleteMultipartUnregistered693=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info694=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info695=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal696=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal697=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key698=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key699=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key700=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key701=== CONT TestIsValidUploadKey702=== RUN TestIsValidUploadKey/narinfo703=== PAUSE TestIsValidUploadKey/narinfo704=== RUN TestIsValidUploadKey/nar_zst705=== PAUSE TestIsValidUploadKey/nar_zst706=== RUN TestIsValidUploadKey/nar_xz707=== PAUSE TestIsValidUploadKey/nar_xz708=== RUN TestIsValidUploadKey/nar_plain709=== PAUSE TestIsValidUploadKey/nar_plain710=== RUN TestIsValidUploadKey/listing711--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)712--- PASS: TestGCTaskStore_Fail (0.00s)713--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)714--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)715--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)716--- PASS: TestGCTaskStore_GetEmpty (0.00s)717--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)718=== CONT TestProxyWriteTimeout7192026/09/29 08:15:46 INFO Shutdown signal received, draining in-flight requests timeout=10s720=== RUN TestProxyWriteTimeout/narinfo721=== PAUSE TestProxyWriteTimeout/narinfo722=== RUN TestProxyWriteTimeout/1_GiB_nar723=== CONT TestReadProxyInvalidPath724--- PASS: TestGenerateLandingPage (0.01s)725=== CONT TestPush_OverlappingRootsStoreOneRowPerKey726=== PAUSE TestProxyWriteTimeout/1_GiB_nar727=== RUN TestProxyWriteTimeout/10_GiB_nar728=== PAUSE TestProxyWriteTimeout/10_GiB_nar729=== RUN TestProxyWriteTimeout/unknown_size730=== PAUSE TestProxyWriteTimeout/unknown_size731=== CONT TestReadRedirectUsesPublicS3URL732--- PASS: TestGCTaskStore_StartNew (0.00s)733=== CONT TestReadProxyRangeRequest734=== PAUSE TestIsValidUploadKey/listing735=== RUN TestIsValidUploadKey/build_log736=== PAUSE TestIsValidUploadKey/build_log737=== RUN TestIsValidUploadKey/build_log_home-manager_file738=== PAUSE TestIsValidUploadKey/build_log_home-manager_file739=== RUN TestIsValidUploadKey/build_log_plus_in_name740=== PAUSE TestIsValidUploadKey/build_log_plus_in_name741=== RUN TestIsValidUploadKey/build_log_question_mark742=== PAUSE TestIsValidUploadKey/build_log_question_mark743=== RUN TestIsValidUploadKey/build_log_equals744=== PAUSE TestIsValidUploadKey/build_log_equals745=== RUN TestIsValidUploadKey/realisation746=== PAUSE TestIsValidUploadKey/realisation747=== RUN TestIsValidUploadKey/realisation_plus_in_output748=== PAUSE TestIsValidUploadKey/realisation_plus_in_output749=== RUN TestIsValidUploadKey/nix-cache-info750=== PAUSE TestIsValidUploadKey/nix-cache-info751=== RUN TestIsValidUploadKey/index.html752=== PAUSE TestIsValidUploadKey/index.html753=== RUN TestIsValidUploadKey/narinfo_key,_nar_type754=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type755=== RUN TestIsValidUploadKey/nar_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type757=== RUN TestIsValidUploadKey/listing_key,_narinfo_type758=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type759=== RUN TestIsValidUploadKey/traversal760=== PAUSE TestIsValidUploadKey/traversal761=== RUN TestIsValidUploadKey/traversal_nar762=== PAUSE TestIsValidUploadKey/traversal_nar763=== RUN TestIsValidUploadKey/absolute764=== PAUSE TestIsValidUploadKey/absolute765=== RUN TestIsValidUploadKey/empty_key766=== PAUSE TestIsValidUploadKey/empty_key767=== RUN TestIsValidUploadKey/unknown_type768=== PAUSE TestIsValidUploadKey/unknown_type769=== CONT TestReadRedirectKeepsNarinfoProxied770--- PASS: TestGracefulShutdownDrainsInflight (0.06s)771=== CONT TestReadRedirectNar7722026-09-29 08:15:46.371 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367732026-09-29 08:15:46.371 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7742026-09-29 08:15:46.389 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367752026-09-29 08:15:46.389 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7762026-09-29 08:15:46.389 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367772026-09-29 08:15:46.389 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC778=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure779=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure780=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart781=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart782=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts783=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts784=== CONT TestReadProxyDisabled7852026-09-29 08:15:46.448 UTC [457] ERROR: relation "goose_db_version" does not exist at character 367862026-09-29 08:15:46.448 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026-09-29 08:15:46.448 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367882026-09-29 08:15:46.448 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7892026-09-29 08:15:46.455 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367902026-09-29 08:15:46.455 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/09/29 08:15:46 OK 20241026095416_initial_model.sql (100.12ms)7922026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (3.37ms)7932026-09-29 08:15:46.504 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367942026-09-29 08:15:46.504 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026/09/29 08:15:46 OK 20241026095416_initial_model.sql (83.02ms)7962026/09/29 08:15:46 OK 20251218171726_add_pins.sql (19.72ms)7972026/09/29 08:15:46 OK 20241026095416_initial_model.sql (36.36ms)7982026/09/29 08:15:46 OK 20241026095416_initial_model.sql (47.11ms)7992026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (16.63ms)8002026/09/29 08:15:46 OK 20241026095416_initial_model.sql (111.47ms)8012026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (15.69ms)8022026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (5.48ms)8032026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (3.98ms)8042026/09/29 08:15:46 OK 20251218171726_add_pins.sql (6.64ms)8052026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (5.74ms)8062026/09/29 08:15:46 OK 20251218171726_add_pins.sql (10.83ms)8072026/09/29 08:15:46 OK 20251218171726_add_pins.sql (9.32ms)8082026-09-29 08:15:46.550 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368092026-09-29 08:15:46.550 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8102026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (11.35ms)8112026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (20.99ms)8122026/09/29 08:15:46 OK 20260905000000_add_claims.sql (37.09ms)8132026/09/29 08:15:46 OK 20251218171726_add_pins.sql (33.62ms)8142026/09/29 08:15:46 OK 20241026095416_initial_model.sql (51.73ms)8152026/09/29 08:15:46 OK 20260905000000_add_claims.sql (21.59ms)8162026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (8ms)8172026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (42.24ms)8182026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (11.85ms)8192026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (12.01ms)8202026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (6.08ms)8212026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (5.45ms)8222026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200008232026-09-29 08:15:46.586 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368242026-09-29 08:15:46.586 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8252026/09/29 08:15:46 OK 20260905000000_add_claims.sql (21.91ms)8262026/09/29 08:15:46 OK 20260905000000_add_claims.sql (11.97ms)8272026/09/29 08:15:46 OK 1_commit_pending_closure.sql (9.07ms)8282026/09/29 08:15:46 OK 2_object_stats_trigger.sql (3.72ms)8292026/09/29 08:15:46 OK 20251218171726_add_pins.sql (13.68ms)8302026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (13.4ms)8312026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200008322026/09/29 08:15:46 OK 20260905000000_add_claims.sql (14.59ms)8332026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (4.98ms)8342026/09/29 08:15:46 OK 20241026095416_initial_model.sql (64.47ms)8352026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (8.61ms)8362026/09/29 08:15:46 OK 3_commit_push.sql (3.18ms)8372026/09/29 08:15:46 goose: up to current file version: 38382026-09-29 08:15:46.598 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368392026-09-29 08:15:46.598 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026-09-29 08:15:46.603 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368412026-09-29 08:15:46.603 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026-09-29 08:15:46.604 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368432026-09-29 08:15:46.604 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8442026-09-29 08:15:46.608 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368452026-09-29 08:15:46.608 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8462026-09-29 08:15:46.608 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368472026-09-29 08:15:46.608 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026/09/29 08:15:46 OK 1_commit_pending_closure.sql (16.32ms)8492026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (14.99ms)8502026/09/29 08:15:46 OK 20241026095416_initial_model.sql (32.71ms)8512026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (21.88ms)8522026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (20.82ms)8532026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200008542026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (19.32ms)8552026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200008562026/09/29 08:15:46 OK 2_object_stats_trigger.sql (6.67ms)8572026-09-29 08:15:46.617 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368582026-09-29 08:15:46.617 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (24.27ms)8602026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (4.9ms)8612026/09/29 08:15:46 OK 1_commit_pending_closure.sql (5.13ms)8622026/09/29 08:15:46 OK 3_commit_push.sql (5.67ms)8632026/09/29 08:15:46 goose: up to current file version: 38642026/09/29 08:15:46 OK 1_commit_pending_closure.sql (6.87ms)8652026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (6.11ms)8662026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200008672026/09/29 08:15:46 OK 20241026095416_initial_model.sql (28.5ms)8682026/09/29 08:15:46 OK 20260905000000_add_claims.sql (8.96ms)8692026-09-29 08:15:46.625 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368702026-09-29 08:15:46.625 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8712026/09/29 08:15:46 OK 2_object_stats_trigger.sql (4.3ms)8722026/09/29 08:15:46 OK 2_object_stats_trigger.sql (3.02ms)8732026-09-29 08:15:46.626 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368742026-09-29 08:15:46.626 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026/09/29 08:15:46 OK 20251218171726_add_pins.sql (15.04ms)8762026/09/29 08:15:46 OK 20251218171726_add_pins.sql (5.95ms)8772026-09-29 08:15:46.630 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368782026-09-29 08:15:46.630 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026/09/29 08:15:46 OK 3_commit_push.sql (4.75ms)8802026/09/29 08:15:46 goose: up to current file version: 38812026/09/29 08:15:46 OK 3_commit_push.sql (4.8ms)8822026/09/29 08:15:46 goose: up to current file version: 38832026/09/29 08:15:46 OK 1_commit_pending_closure.sql (6.58ms)8842026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (7.07ms)8852026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (7.22ms)8862026-09-29 08:15:46.632 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368872026-09-29 08:15:46.632 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8882026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (5.79ms)8892026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (11.55ms)8902026/09/29 08:15:46 OK 20241026095416_initial_model.sql (23.26ms)8912026-09-29 08:15:46.642 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368922026-09-29 08:15:46.642 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8932026/09/29 08:15:46 OK 2_object_stats_trigger.sql (11.75ms)8942026-09-29 08:15:46.644 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368952026-09-29 08:15:46.644 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026/09/29 08:15:46 OK 20241026095416_initial_model.sql (19.48ms)8972026-09-29 08:15:46.647 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368982026-09-29 08:15:46.647 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026/09/29 08:15:46 OK 3_commit_push.sql (4.27ms)9002026/09/29 08:15:46 goose: up to current file version: 39012026/09/29 08:15:46 OK 20260905000000_add_claims.sql (9.5ms)9022026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (6.89ms)9032026/09/29 08:15:46 OK 20241026095416_initial_model.sql (21.1ms)9042026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (15.28ms)9052026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200009062026/09/29 08:15:46 OK 20251218171726_add_pins.sql (15.27ms)9072026/09/29 08:15:46 OK 20260905000000_add_claims.sql (16.05ms)9082026/09/29 08:15:46 OK 20241026095416_initial_model.sql (23.62ms)9092026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (6.17ms)9102026/09/29 08:15:46 OK 1_commit_pending_closure.sql (5.19ms)9112026/09/29 08:15:46 OK 20251218171726_add_pins.sql (8.06ms)9122026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (8.19ms)9132026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (7.16ms)9142026/09/29 08:15:46 OK 20241026095416_initial_model.sql (16.51ms)9152026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (5.54ms)9162026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (8.45ms)9172026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (9.75ms)9182026/09/29 08:15:46 OK 20241026095416_initial_model.sql (27.36ms)9192026/09/29 08:15:46 OK 20251218171726_add_pins.sql (8.32ms)9202026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (4.82ms)9212026/09/29 08:15:46 OK 20241026095416_initial_model.sql (27.97ms)9222026/09/29 08:15:46 OK 2_object_stats_trigger.sql (7.44ms)9232026-09-29 08:15:46.661 UTC [475] ERROR: relation "goose_db_version" does not exist at character 369242026-09-29 08:15:46.661 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (6.53ms)9262026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200009272026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (4.59ms)9282026/09/29 08:15:46 OK 3_commit_push.sql (2.88ms)9292026/09/29 08:15:46 OK 20251218171726_add_pins.sql (8.2ms)9302026/09/29 08:15:46 OK 20251218171726_add_pins.sql (8.16ms)9312026/09/29 08:15:46 goose: up to current file version: 39322026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (11.04ms)9332026/09/29 08:15:46 OK 20241026095416_initial_model.sql (25.41ms)9342026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (12.57ms)9352026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (7.4ms)9362026/09/29 08:15:46 OK 20241026095416_initial_model.sql (20ms)9372026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200009382026/09/29 08:15:46 OK 20260905000000_add_claims.sql (11.41ms)9392026/09/29 08:15:46 OK 1_commit_pending_closure.sql (6.82ms)9402026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (5.63ms)9412026-09-29 08:15:46.670 UTC [477] ERROR: relation "goose_db_version" does not exist at character 369422026-09-29 08:15:46.670 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9432026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (6.73ms)9442026/09/29 08:15:46 OK 20251218171726_add_pins.sql (10.45ms)9452026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (13.36ms)9462026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (5.84ms)9472026/09/29 08:15:46 OK 20241026095416_initial_model.sql (18.61ms)9482026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (5.63ms)9492026/09/29 08:15:46 OK 1_commit_pending_closure.sql (9.9ms)9502026/09/29 08:15:46 OK 20251218171726_add_pins.sql (15.93ms)9512026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (10.39ms)9522026/09/29 08:15:46 OK 20260905000000_add_claims.sql (13.27ms)9532026/09/29 08:15:46 OK 2_object_stats_trigger.sql (11.35ms)9542026/09/29 08:15:46 OK 20260905000000_add_claims.sql (9.63ms)9552026/09/29 08:15:46 OK 20260905000000_add_claims.sql (11.65ms)9562026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (7.66ms)9572026/09/29 08:15:46 OK 20251218171726_add_pins.sql (13.56ms)9582026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (10.8ms)9592026/09/29 08:15:46 OK 2_object_stats_trigger.sql (3.42ms)9602026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (9.14ms)9612026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200009622026/09/29 08:15:46 OK 20260905000000_add_claims.sql (11.51ms)9632026/09/29 08:15:46 OK 20241026095416_initial_model.sql (25.38ms)9642026/09/29 08:15:46 OK 3_commit_push.sql (4.6ms)9652026/09/29 08:15:46 goose: up to current file version: 39662026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (5.57ms)9672026/09/29 08:15:46 OK 20241026095416_initial_model.sql (35.35ms)9682026/09/29 08:15:46 OK 20251218171726_add_pins.sql (15.06ms)9692026/09/29 08:15:46 OK 1_commit_pending_closure.sql (5.27ms)9702026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (10.45ms)9712026/09/29 08:15:46 OK 20251218171726_add_pins.sql (10.23ms)9722026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (7.55ms)9732026/09/29 08:15:46 OK 20251218171726_add_pins.sql (7.29ms)9742026/09/29 08:15:46 OK 3_commit_push.sql (7.18ms)9752026/09/29 08:15:46 goose: up to current file version: 39762026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (9.22ms)9772026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (4.46ms)9782026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200009792026/09/29 08:15:46 OK 20260905000000_add_claims.sql (8.29ms)9802026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (4.71ms)9812026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (5.67ms)9822026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (9.54ms)9832026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (3.96ms)9842026/09/29 08:15:46 OK 20241026095416_initial_model.sql (38.69ms)9852026/09/29 08:15:46 OK 2_object_stats_trigger.sql (5.52ms)9862026/09/29 08:15:46 OK 20241026095416_initial_model.sql (13.94ms)9872026/09/29 08:15:46 OK 1_commit_pending_closure.sql (8.82ms)9882026/09/29 08:15:46 OK 20260905000000_add_claims.sql (9.11ms)9892026/09/29 08:15:46 OK 2_object_stats_trigger.sql (2.02ms)9902026/09/29 08:15:46 OK 20260905000000_add_claims.sql (11.85ms)9912026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (7.41ms)9922026/09/29 08:15:46 OK 3_commit_push.sql (6.71ms)9932026/09/29 08:15:46 goose: up to current file version: 39942026/09/29 08:15:46 OK 20251218171726_add_pins.sql (10.17ms)9952026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (12.54ms)9962026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (12.64ms)9972026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200009982026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (12.73ms)9992026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (11.18ms)10002026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010012026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (5.98ms)10022026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (14.02ms)10032026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (14.57ms)10042026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010052026/09/29 08:15:46 OK 3_commit_push.sql (4.58ms)10062026/09/29 08:15:46 goose: up to current file version: 310072026/09/29 08:15:46 OK 20260905000000_add_claims.sql (8.21ms)10082026/09/29 08:15:46 OK 1_commit_pending_closure.sql (7.9ms)10092026/09/29 08:15:46 OK 20251218171726_add_pins.sql (21.24ms)10102026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (22.73ms)10112026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (15.34ms)10122026/09/29 08:15:46 OK 1_commit_pending_closure.sql (13.34ms)10132026/09/29 08:15:46 OK 2_object_stats_trigger.sql (8.23ms)10142026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (17.37ms)10152026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (9.8ms)10162026/09/29 08:15:46 OK 2_object_stats_trigger.sql (4.42ms)10172026/09/29 08:15:46 OK 20241026095416_initial_model.sql (29.96ms)10182026/09/29 08:15:46 OK 20260905000000_add_claims.sql (8.89ms)10192026/09/29 08:15:46 OK 20260905000000_add_claims.sql (18.3ms)10202026/09/29 08:15:46 OK 20251218171726_add_pins.sql (19.74ms)10212026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (16.98ms)10222026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010232026/09/29 08:15:46 OK 3_commit_push.sql (2.4ms)10242026/09/29 08:15:46 goose: up to current file version: 310252026/09/29 08:15:46 OK 20251218171726_add_pins.sql (18.51ms)10262026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (5.12ms)10272026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010282026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (20.89ms)10292026/09/29 08:15:46 OK 1_commit_pending_closure.sql (19.43ms)10302026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (8.1ms)10312026/09/29 08:15:46 OK 1_commit_pending_closure.sql (5.18ms)10322026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (6.5ms)10332026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010342026/09/29 08:15:46 OK 3_commit_push.sql (6.54ms)10352026/09/29 08:15:46 goose: up to current file version: 310362026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (6.11ms)10372026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (7.01ms)10382026/09/29 08:15:46 OK 20260905000000_add_claims.sql (7.25ms)10392026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (7.93ms)10402026/09/29 08:15:46 OK 2_object_stats_trigger.sql (5.12ms)10412026/09/29 08:15:46 OK 1_commit_pending_closure.sql (7.92ms)10422026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (12.54ms)10432026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (13.06ms)10442026/09/29 08:15:46 OK 2_object_stats_trigger.sql (7.76ms)10452026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010462026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (7.99ms)10472026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010482026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (16.32ms)10492026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (9.65ms)10502026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010512026/09/29 08:15:46 OK 3_commit_push.sql (8.14ms)10522026/09/29 08:15:46 goose: up to current file version: 310532026/09/29 08:15:46 OK 2_object_stats_trigger.sql (8.23ms)10542026/09/29 08:15:46 OK 1_commit_pending_closure.sql (10.74ms)10552026/09/29 08:15:46 OK 20260905000000_add_claims.sql (13.84ms)10562026/09/29 08:15:46 OK 3_commit_push.sql (4.56ms)10572026/09/29 08:15:46 goose: up to current file version: 310582026/09/29 08:15:46 OK 20251218171726_add_pins.sql (12.31ms)10592026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (10.94ms)10602026/09/29 08:15:46 INFO Received uploads request method=POST path=/api/pending_closures10612026/09/29 08:15:46 OK 1_commit_pending_closure.sql (8.19ms)10622026/09/29 08:15:46 OK 20260905000000_add_claims.sql (8.68ms)10632026/09/29 08:15:46 OK 1_commit_pending_closure.sql (6.17ms)10642026/09/29 08:15:46 OK 20260905000000_add_claims.sql (5.98ms)10652026/09/29 08:15:46 OK 2_object_stats_trigger.sql (5.64ms)10662026/09/29 08:15:46 OK 3_commit_push.sql (5.71ms)10672026/09/29 08:15:46 goose: up to current file version: 310682026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (6.44ms)10692026/09/29 08:15:46 OK 1_commit_pending_closure.sql (7.29ms)10702026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (4.74ms)10712026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010722026/09/29 08:15:46 OK 2_object_stats_trigger.sql (2.32ms)10732026/09/29 08:15:46 OK 2_object_stats_trigger.sql (3.22ms)10742026/09/29 08:15:46 OK 3_commit_push.sql (1.61ms)10752026/09/29 08:15:46 goose: up to current file version: 310762026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (7.93ms)10772026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (4.91ms)10782026/09/29 08:15:46 OK 2_object_stats_trigger.sql (3.78ms)10792026/09/29 08:15:46 OK 3_commit_push.sql (4.89ms)10802026/09/29 08:15:46 goose: up to current file version: 310812026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (6.11ms)10822026/09/29 08:15:46 OK 3_commit_push.sql (2.71ms)10832026/09/29 08:15:46 goose: up to current file version: 310842026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (4.86ms)10852026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010862026/09/29 08:15:46 OK 1_commit_pending_closure.sql (5ms)1087=== NAME TestNARDeduplicationMetadataUploadBug1088 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug725952978/001/store/y8w58q1rv9grn2ib88rz4ydsaxb2ai0p-file1.txt10892026/09/29 08:15:46 OK 2_object_stats_trigger.sql (2.79ms)10902026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (4.28ms)10912026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010922026/09/29 08:15:46 OK 3_commit_push.sql (5.42ms)10932026/09/29 08:15:46 goose: up to current file version: 310942026/09/29 08:15:46 OK 20260905000000_add_claims.sql (6.62ms)10952026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (4.58ms)10962026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000010972026/09/29 08:15:46 OK 1_commit_pending_closure.sql (4.36ms)10982026/09/29 08:15:46 OK 3_commit_push.sql (4.19ms)10992026/09/29 08:15:46 goose: up to current file version: 311002026/09/29 08:15:46 OK 2_object_stats_trigger.sql (3.02ms)11012026/09/29 08:15:46 OK 1_commit_pending_closure.sql (3.15ms)11022026/09/29 08:15:46 OK 1_commit_pending_closure.sql (4.7ms)11032026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (4.44ms)11042026/09/29 08:15:46 OK 2_object_stats_trigger.sql (1.56ms)11052026/09/29 08:15:46 OK 2_object_stats_trigger.sql (2.47ms)11062026/09/29 08:15:46 OK 3_commit_push.sql (2.57ms)11072026/09/29 08:15:46 goose: up to current file version: 311082026/09/29 08:15:46 OK 3_commit_push.sql (2.84ms)11092026/09/29 08:15:46 goose: up to current file version: 311102026/09/29 08:15:46 OK 3_commit_push.sql (2.6ms)11112026/09/29 08:15:46 goose: up to current file version: 311122026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (4.27ms)11132026/09/29 08:15:46 goose: successfully migrated database to version: 2026092312000011142026/09/29 08:15:46 OK 1_commit_pending_closure.sql (2.3ms)11152026/09/29 08:15:46 OK 2_object_stats_trigger.sql (2.25ms)11162026/09/29 08:15:46 OK 3_commit_push.sql (1.84ms)11172026/09/29 08:15:46 goose: up to current file version: 311182026/09/29 08:15:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11192026/09/29 08:15:46 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1120--- PASS: TestCompleteMultipartUnregistered (0.54s)1121=== CONT TestReadProxyRootRedirectsToIndexHTML11222026/09/29 08:15:46 INFO Received push request method=POST path=/api/pushes11232026/09/29 08:15:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11242026/09/29 08:15:46 INFO Uploading y8w58q1rv9grn2ib88rz4ydsaxb2ai0p-file1.txt (160B)11252026/09/29 08:15:46 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11262026/09/29 08:15:46 WARN Failed to register uploaded object key=y8w58q1rv9grn2ib88rz4ydsaxb2ai0p.ls error="server returned 404: 404 page not found\n"11272026/09/29 08:15:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11282026/09/29 08:15:46 INFO Signed narinfos id=1 count=111292026/09/29 08:15:46 INFO Uploading 1 narinfos11302026/09/29 08:15:46 INFO Received uploads request method=POST path=/api/pending_closures11312026/09/29 08:15:46 INFO Received complete push request method=POST path=/api/pushes/1/complete11322026/09/29 08:15:46 WARN Failed to register uploaded object key=y8w58q1rv9grn2ib88rz4ydsaxb2ai0p.narinfo error="server returned 404: 404 page not found\n"11332026/09/29 08:15:46 INFO Upload complete. (104ms)1134=== NAME TestNARDeduplicationMetadataUploadBug1135 metadata_upload_test.go:54: Retrieved narinfo from S3:1136 StorePath: /build/TestNARDeduplicationMetadataUploadBug725952978/001/store/y8w58q1rv9grn2ib88rz4ydsaxb2ai0p-file1.txt1137 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1138 Compression: zstd1139 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1140 NarSize: 1601141 References: 1142 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1143 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1144 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1145 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11462026-09-29 08:15:46.924 UTC [533] ERROR: relation "goose_db_version" does not exist at character 3611472026-09-29 08:15:46.924 UTC [533] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026/09/29 08:15:46 OK 20241026095416_initial_model.sql (10.65ms)11492026/09/29 08:15:46 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)11502026/09/29 08:15:46 OK 20251218171726_add_pins.sql (3.93ms)11512026/09/29 08:15:46 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)1152 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug725952978/001/store/qgbacjig9518px6kl3db20nms71wpzhg-file2.txt11532026/09/29 08:15:46 OK 20260905000000_add_claims.sql (5.75ms)11542026/09/29 08:15:46 OK 20260920000000_drop_claims.sql (5.58ms)11552026/09/29 08:15:46 OK 20260923120000_add_pushes.sql (3.53ms)11562026/09/29 08:15:46 goose: successfully migrated database to version: 202609231200001157--- PASS: TestObjectStatsTrigger (0.71s)1158=== CONT TestReadProxyConditionalGet11592026/09/29 08:15:46 OK 1_commit_pending_closure.sql (3.59ms)11602026/09/29 08:15:46 OK 2_object_stats_trigger.sql (1.21ms)11612026/09/29 08:15:46 OK 3_commit_push.sql (1ms)11622026/09/29 08:15:46 goose: up to current file version: 311632026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/29 08:15:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11652026/09/29 08:15:47 INFO Received push request method=POST path=/api/pushes11662026/09/29 08:15:47 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11672026/09/29 08:15:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11682026/09/29 08:15:47 INFO Signed narinfos id=2 count=111692026/09/29 08:15:47 INFO Uploading 1 narinfos11702026/09/29 08:15:47 WARN Failed to register uploaded object key=qgbacjig9518px6kl3db20nms71wpzhg.ls error="server returned 404: 404 page not found\n"11712026/09/29 08:15:47 INFO Received complete push request method=POST path=/api/pushes/2/complete11722026/09/29 08:15:47 WARN Failed to register uploaded object key=qgbacjig9518px6kl3db20nms71wpzhg.narinfo error="server returned 404: 404 page not found\n"11732026/09/29 08:15:47 INFO Upload complete. (71ms)11742026-09-29 08:15:47.070 UTC [593] ERROR: relation "goose_db_version" does not exist at character 3611752026-09-29 08:15:47.070 UTC [593] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1176=== NAME TestNARDeduplicationMetadataUploadBug1177 metadata_upload_test.go:76: Retrieved narinfo from S3:1178 StorePath: /build/TestNARDeduplicationMetadataUploadBug725952978/001/store/qgbacjig9518px6kl3db20nms71wpzhg-file2.txt1179 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1180 Compression: zstd1181 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1182 NarSize: 1601183 References: 1184 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1185 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1186 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1187 {"version":1,"root":{"type":"regular","size":44}}1188--- PASS: TestNARDeduplicationMetadataUploadBug (0.83s)1189=== CONT TestReadProxyHead11902026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures11912026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures11922026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures11932026/09/29 08:15:47 OK 20241026095416_initial_model.sql (13.84ms)11942026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)11952026/09/29 08:15:47 OK 20251218171726_add_pins.sql (4.87ms)11962026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)11972026/09/29 08:15:47 OK 20260905000000_add_claims.sql (13.1ms)11982026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (8.88ms)11992026/09/29 08:15:47 INFO Received cleanup request method=DELETE path=/api/pending_closures12002026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (5.54ms)12012026/09/29 08:15:47 goose: successfully migrated database to version: 202609231200001202=== NAME TestOrphanedObjectsGC1203 orphaned_objects_gc_test.go:290: GC Test Summary:1204 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1205 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1206 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1207 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1208 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1209--- PASS: TestOrphanedObjectsGC (0.88s)1210=== CONT TestCompletedNarNotReofferedAcrossClosures12112026/09/29 08:15:47 OK 1_commit_pending_closure.sql (4.83ms)12122026/09/29 08:15:47 OK 2_object_stats_trigger.sql (3.41ms)12132026/09/29 08:15:47 INFO Aborted multipart uploads count=112142026/09/29 08:15:47 OK 3_commit_push.sql (4.63ms)12152026/09/29 08:15:47 goose: up to current file version: 31216--- PASS: TestService_healthCheckHandler (0.89s)1217=== CONT TestSkippedUploadsHandler12182026/09/29 08:15:47 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001219--- PASS: TestSkippedUploadsHandler (0.00s)1220=== CONT TestParseSize1221--- PASS: TestParseSize (0.00s)1222=== CONT TestService_Rustfstest1223--- PASS: TestMultipartCleanup (0.90s)1224=== CONT TestPresignedUploadRegisteredBeforeCommit12252026-09-29 08:15:47.179 UTC [604] ERROR: relation "goose_db_version" does not exist at character 3612262026-09-29 08:15:47.179 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12272026/09/29 08:15:47 OK 20241026095416_initial_model.sql (13.8ms)12282026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (5.71ms)12292026/09/29 08:15:47 INFO Received push request method=POST path=/api/pushes12302026/09/29 08:15:47 OK 20251218171726_add_pins.sql (15.38ms)12312026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (6.16ms)12322026/09/29 08:15:47 OK 20260905000000_add_claims.sql (6.13ms)12332026-09-29 08:15:47.238 UTC [605] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-29 08:15:47.238 UTC [605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (3.75ms)12362026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (3.87ms)12372026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000012382026/09/29 08:15:47 OK 1_commit_pending_closure.sql (3.97ms)12392026/09/29 08:15:47 INFO Received complete push request method=POST path=/api/pushes/1/complete12402026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.82ms)12412026/09/29 08:15:47 OK 3_commit_push.sql (2.18ms)12422026-09-29 08:15:47.255 UTC [608] ERROR: relation "goose_db_version" does not exist at character 3612432026-09-29 08:15:47.255 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026/09/29 08:15:47 goose: up to current file version: 312452026-09-29 08:15:47.257 UTC [609] ERROR: relation "goose_db_version" does not exist at character 3612462026-09-29 08:15:47.257 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12472026/09/29 08:15:47 OK 20241026095416_initial_model.sql (12.68ms)12482026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (2ms)1249--- PASS: TestPush_CompleteCommitsEveryRoot (1.01s)1250=== CONT TestService_ReadScope_PublicByDefault12512026/09/29 08:15:47 OK 20251218171726_add_pins.sql (15.39ms)12522026/09/29 08:15:47 OK 20241026095416_initial_model.sql (15.51ms)12532026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (4.92ms)12542026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (6.76ms)12552026/09/29 08:15:47 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1256--- PASS: TestService_AuthMiddleware (1.03s)1257=== CONT TestClientErrorHandling1258=== RUN TestClientErrorHandling/InvalidStorePath1259=== PAUSE TestClientErrorHandling/InvalidStorePath1260=== RUN TestClientErrorHandling/InvalidAuthToken1261=== PAUSE TestClientErrorHandling/InvalidAuthToken1262=== RUN TestClientErrorHandling/ServerNotAvailable1263=== PAUSE TestClientErrorHandling/ServerNotAvailable1264=== CONT TestClientCADerivations12652026/09/29 08:15:47 OK 20241026095416_initial_model.sql (14.21ms)12662026/09/29 08:15:47 OK 20251218171726_add_pins.sql (6.99ms)12672026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (6.95ms)12682026/09/29 08:15:47 OK 20260905000000_add_claims.sql (10.56ms)12692026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (8.76ms)12702026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (5.26ms)12712026/09/29 08:15:47 OK 20251218171726_add_pins.sql (7.47ms)12722026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (4.41ms)12732026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000012742026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)12752026/09/29 08:15:47 OK 20260905000000_add_claims.sql (7.43ms)12762026/09/29 08:15:47 OK 1_commit_pending_closure.sql (6.71ms)12772026/09/29 08:15:47 OK 20260905000000_add_claims.sql (6.76ms)12782026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (7.55ms)12792026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.77ms)12802026/09/29 08:15:47 OK 3_commit_push.sql (1.58ms)12812026/09/29 08:15:47 goose: up to current file version: 312822026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (2.69ms)12832026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000012842026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (3.91ms)12852026/09/29 08:15:47 OK 1_commit_pending_closure.sql (3.71ms)12862026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (4.39ms)12872026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000012882026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.83ms)12892026/09/29 08:15:47 OK 1_commit_pending_closure.sql (5.56ms)12902026/09/29 08:15:47 OK 3_commit_push.sql (4.5ms)12912026/09/29 08:15:47 goose: up to current file version: 312922026/09/29 08:15:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12932026/09/29 08:15:47 OK 2_object_stats_trigger.sql (5.77ms)12942026/09/29 08:15:47 OK 3_commit_push.sql (1.92ms)12952026/09/29 08:15:47 goose: up to current file version: 312962026/09/29 08:15:47 INFO Received cleanup request method=DELETE path=/api/pending_closures12972026/09/29 08:15:47 INFO Aborted multipart uploads count=012982026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures12992026-09-29 08:15:47.353 UTC [614] ERROR: relation "goose_db_version" does not exist at character 3613002026-09-29 08:15:47.353 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13012026/09/29 08:15:47 INFO Received cleanup request method=DELETE path=/api/pending_closures13022026/09/29 08:15:47 INFO Aborted multipart uploads count=113032026/09/29 08:15:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13042026-09-29 08:15:47.378 UTC [466] ERROR: Closure does not exist: id=113052026-09-29 08:15:47.378 UTC [466] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE13062026-09-29 08:15:47.378 UTC [466] STATEMENT: -- name: CommitPendingClosure :exec1307 SELECT commit_pending_closure($1::bigint)1308 1309--- PASS: TestService_cleanupPendingClosuresHandler (1.12s)1310=== CONT TestCacheStatsHandler13112026-09-29 08:15:47.380 UTC [630] ERROR: relation "goose_db_version" does not exist at character 3613122026-09-29 08:15:47.380 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13132026/09/29 08:15:47 OK 20241026095416_initial_model.sql (20.93ms)13142026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (3.86ms)13152026/09/29 08:15:47 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDAyYWI3NjgtNzBhZi00NDRlLTlmNTctMTZlZmMzYTdiMGQ5LjEwMTE5Zjk3LThiODYtNGYxNy1iYmMzLTQ0ZGViOTkzYzAyMngxNzkwNjY5NzQ2NzU4OTgzMjg5 parts=1013162026/09/29 08:15:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13172026/09/29 08:15:47 OK 20251218171726_add_pins.sql (9.34ms)13182026/09/29 08:15:47 INFO Completed upload id=113192026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (12.21ms)13202026/09/29 08:15:47 OK 20241026095416_initial_model.sql (13.1ms)13212026/09/29 08:15:47 WARN readiness check failed error="closed pool"1322--- PASS: TestService_readinessHandler (1.15s)1323=== CONT TestCacheConfigHandler1324=== RUN TestCacheConfigHandler/full_config,_no_issuer1325=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1326=== RUN TestCacheConfigHandler/no_cache_url_configured1327=== PAUSE TestCacheConfigHandler/no_cache_url_configured1328=== RUN TestCacheConfigHandler/no_signing_keys1329=== PAUSE TestCacheConfigHandler/no_signing_keys1330=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1331=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1332=== CONT TestService_RequireScope_OIDC13332026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures13342026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (12.48ms)13352026/09/29 08:15:47 OK 20260905000000_add_claims.sql (14.39ms)13362026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures13372026/09/29 08:15:47 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13382026/09/29 08:15:47 WARN Found objects in DB but missing from S3, will re-upload count=113392026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (9.77ms)1340--- PASS: TestService_verifyS3Integrity (1.17s)1341=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13422026/09/29 08:15:47 OK 20251218171726_add_pins.sql (16.85ms)13432026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (8.87ms)13442026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000013452026/09/29 08:15:47 OK 1_commit_pending_closure.sql (9.59ms)13462026/09/29 08:15:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39615/oidc13472026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (16.73ms)13482026/09/29 08:15:47 OK 2_object_stats_trigger.sql (6ms)13492026/09/29 08:15:47 OK 3_commit_push.sql (8.01ms)13502026/09/29 08:15:47 goose: up to current file version: 313512026/09/29 08:15:47 OK 20260905000000_add_claims.sql (11.04ms)13522026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (10.04ms)13532026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (8.32ms)13542026-09-29 08:15:47.484 UTC [637] ERROR: relation "goose_db_version" does not exist at character 3613552026-09-29 08:15:47.484 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000013572026/09/29 08:15:47 OK 1_commit_pending_closure.sql (4.05ms)13582026/09/29 08:15:47 OK 2_object_stats_trigger.sql (10ms)13592026/09/29 08:15:47 OK 3_commit_push.sql (2.87ms)13602026/09/29 08:15:47 goose: up to current file version: 313612026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures13622026/09/29 08:15:47 OK 20241026095416_initial_model.sql (25.41ms)13632026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (4.71ms)13642026/09/29 08:15:47 OK 20251218171726_add_pins.sql (6ms)13652026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)13662026-09-29 08:15:47.541 UTC [638] ERROR: relation "goose_db_version" does not exist at character 3613672026-09-29 08:15:47.541 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13682026/09/29 08:15:47 OK 20260905000000_add_claims.sql (4.77ms)1369--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.29s)1370=== CONT TestService_AuthMiddleware_OIDC13712026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (5.01ms)13722026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (2.9ms)13732026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000013742026/09/29 08:15:47 OK 1_commit_pending_closure.sql (7.17ms)13752026/09/29 08:15:47 OK 20241026095416_initial_model.sql (11.29ms)13762026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.22ms)13772026/09/29 08:15:47 OK 3_commit_push.sql (1.33ms)13782026/09/29 08:15:47 goose: up to current file version: 313792026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)13802026/09/29 08:15:47 OK 20251218171726_add_pins.sql (4.73ms)13812026-09-29 08:15:47.569 UTC [639] ERROR: relation "goose_db_version" does not exist at character 3613822026-09-29 08:15:47.569 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13832026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)13842026/09/29 08:15:47 OK 20260905000000_add_claims.sql (4.63ms)13852026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (3.5ms)13862026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (3.63ms)13872026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000013882026/09/29 08:15:47 OK 1_commit_pending_closure.sql (3.71ms)13892026/09/29 08:15:47 OK 20241026095416_initial_model.sql (11.62ms)1390--- PASS: TestReadProxyRangeRequest (1.27s)1391=== CONT TestService_AuthMiddleware_MTLSProxyHeader13922026/09/29 08:15:47 OK 2_object_stats_trigger.sql (3.04ms)13932026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)13942026/09/29 08:15:47 OK 3_commit_push.sql (1.63ms)13952026/09/29 08:15:47 goose: up to current file version: 313962026/09/29 08:15:47 OK 20251218171726_add_pins.sql (3.97ms)13972026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)13982026/09/29 08:15:47 OK 20260905000000_add_claims.sql (5.04ms)13992026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (6.88ms)14002026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (3.11ms)14012026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000014022026/09/29 08:15:47 OK 1_commit_pending_closure.sql (5.36ms)14032026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.52ms)14042026/09/29 08:15:47 OK 3_commit_push.sql (2.25ms)14052026/09/29 08:15:47 goose: up to current file version: 31406--- PASS: TestMetricsInventory (1.39s)1407=== CONT TestService_ReadAuthMiddleware14082026/09/29 08:15:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14092026-09-29 08:15:47.676 UTC [644] ERROR: relation "goose_db_version" does not exist at character 3614102026-09-29 08:15:47.676 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14112026/09/29 08:15:47 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDAyYWI3NjgtNzBhZi00NDRlLTlmNTctMTZlZmMzYTdiMGQ5LjQ4NWI0OTE2LWJkNWEtNGI2Yi1hNDVhLWI4NmRhYTIyYzFhZngxNzkwNjY5NzQ3MTA1NTI1Mzgw parts=1014122026/09/29 08:15:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14132026/09/29 08:15:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42219/oidc14142026/09/29 08:15:47 OK 20241026095416_initial_model.sql (13.68ms)14152026/09/29 08:15:47 INFO Completed upload id=114162026/09/29 08:15:47 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014172026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (7.89ms)14182026/09/29 08:15:47 INFO Received uploads request method=POST path=/api/pending_closures14192026/09/29 08:15:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures14202026/09/29 08:15:47 INFO Aborted multipart uploads count=014212026/09/29 08:15:47 OK 20251218171726_add_pins.sql (11.5ms)14222026/09/29 08:15:47 WARN Force mode enabled - objects will be deleted immediately without grace period14232026/09/29 08:15:47 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=014242026/09/29 08:15:47 INFO Aborted multipart uploads count=014252026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (7.49ms)14262026/09/29 08:15:47 INFO Vacuumed table table=pending_closures14272026/09/29 08:15:47 INFO Vacuumed table table=pending_objects14282026/09/29 08:15:47 INFO Vacuumed table table=multipart_uploads14292026/09/29 08:15:47 INFO Vacuumed table table=closures14302026/09/29 08:15:47 INFO Vacuumed table table=objects14312026/09/29 08:15:47 OK 20260905000000_add_claims.sql (6.85ms)14322026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (4.34ms)1433--- PASS: TestGCMetrics (1.48s)1434=== CONT TestPush_SignsNarinfosOfItsPendingObjects14352026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (3.25ms)14362026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000014372026-09-29 08:15:47.741 UTC [649] ERROR: relation "goose_db_version" does not exist at character 3614382026-09-29 08:15:47.741 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026/09/29 08:15:47 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=014402026/09/29 08:15:47 OK 1_commit_pending_closure.sql (4.16ms)14412026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.19ms)14422026/09/29 08:15:47 OK 3_commit_push.sql (6.57ms)14432026/09/29 08:15:47 goose: up to current file version: 314442026/09/29 08:15:47 INFO Vacuumed table table=pending_closures14452026/09/29 08:15:47 INFO Vacuumed table table=pending_objects14462026/09/29 08:15:47 INFO Vacuumed table table=multipart_uploads14472026/09/29 08:15:47 OK 20241026095416_initial_model.sql (18.55ms)14482026/09/29 08:15:47 INFO Vacuumed table table=closures14492026/09/29 08:15:47 INFO Vacuumed table table=objects14502026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (8.71ms)1451--- PASS: TestReadRedirectUsesPublicS3URL (1.46s)1452=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14532026/09/29 08:15:47 OK 20251218171726_add_pins.sql (5.33ms)14542026-09-29 08:15:47.784 UTC [652] ERROR: relation "goose_db_version" does not exist at character 3614552026-09-29 08:15:47.784 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14562026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (11.29ms)14572026/09/29 08:15:47 OK 20260905000000_add_claims.sql (4.72ms)14582026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (3.53ms)14592026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (3.94ms)14602026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000014612026/09/29 08:15:47 OK 1_commit_pending_closure.sql (5ms)14622026/09/29 08:15:47 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001463--- PASS: TestService_createPendingClosureHandler (1.55s)1464=== CONT TestRedundantMultipartUpload14652026/09/29 08:15:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14662026/09/29 08:15:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1467--- PASS: TestService_NativeMTLS (1.56s)1468=== CONT TestCreatePin_ReservedPins14692026/09/29 08:15:47 OK 20241026095416_initial_model.sql (17.7ms)14702026/09/29 08:15:47 OK 2_object_stats_trigger.sql (8.95ms)14712026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (4.52ms)14722026/09/29 08:15:47 OK 3_commit_push.sql (2.08ms)14732026/09/29 08:15:47 goose: up to current file version: 314742026/09/29 08:15:47 OK 20251218171726_add_pins.sql (3.68ms)14752026-09-29 08:15:47.836 UTC [657] ERROR: relation "goose_db_version" does not exist at character 3614762026-09-29 08:15:47.836 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14772026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (15.23ms)14782026/09/29 08:15:47 OK 20260905000000_add_claims.sql (10.29ms)14792026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (3.54ms)14802026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (3.07ms)14812026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000014822026/09/29 08:15:47 INFO Received push request method=POST path=/api/pushes14832026/09/29 08:15:47 OK 1_commit_pending_closure.sql (10.41ms)14842026/09/29 08:15:47 OK 20241026095416_initial_model.sql (21.95ms)14852026/09/29 08:15:47 OK 2_object_stats_trigger.sql (3.27ms)14862026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)14872026-09-29 08:15:47.875 UTC [658] ERROR: relation "goose_db_version" does not exist at character 3614882026-09-29 08:15:47.875 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14892026/09/29 08:15:47 OK 3_commit_push.sql (3.17ms)14902026/09/29 08:15:47 goose: up to current file version: 314912026/09/29 08:15:47 OK 20251218171726_add_pins.sql (4.43ms)14922026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (5.9ms)14932026/09/29 08:15:47 OK 20260905000000_add_claims.sql (8.22ms)14942026/09/29 08:15:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43451/oidc14952026/09/29 08:15:47 OK 20241026095416_initial_model.sql (16.17ms)14962026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (5.13ms)1497--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.63s)1498=== CONT TestProxyHeadersOnlyTrustedOnSocket14992026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (2.77ms)15002026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000015012026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)15022026-09-29 08:15:47.909 UTC [663] ERROR: relation "goose_db_version" does not exist at character 3615032026-09-29 08:15:47.909 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15042026/09/29 08:15:47 OK 1_commit_pending_closure.sql (7.67ms)15052026/09/29 08:15:47 OK 20251218171726_add_pins.sql (7.91ms)15062026/09/29 08:15:47 OK 2_object_stats_trigger.sql (2.18ms)15072026/09/29 08:15:47 OK 3_commit_push.sql (2.11ms)15082026/09/29 08:15:47 goose: up to current file version: 315092026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)15102026/09/29 08:15:47 OK 20260905000000_add_claims.sql (8.56ms)15112026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (4.63ms)15122026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (4.58ms)15132026/09/29 08:15:47 goose: successfully migrated database to version: 2026092312000015142026/09/29 08:15:47 OK 20241026095416_initial_model.sql (19.85ms)15152026/09/29 08:15:47 OK 1_commit_pending_closure.sql (4.8ms)1516--- PASS: TestReadRedirectKeepsNarinfoProxied (1.61s)1517=== CONT TestParseSingleRange1518=== RUN TestParseSingleRange/none1519=== PAUSE TestParseSingleRange/none1520=== RUN TestParseSingleRange/unknown_unit1521=== PAUSE TestParseSingleRange/unknown_unit1522=== RUN TestParseSingleRange/multi-range_ignored1523=== PAUSE TestParseSingleRange/multi-range_ignored1524=== RUN TestParseSingleRange/malformed_no_dash1525=== PAUSE TestParseSingleRange/malformed_no_dash1526=== RUN TestParseSingleRange/malformed_both_empty1527=== PAUSE TestParseSingleRange/malformed_both_empty1528=== RUN TestParseSingleRange/malformed_end_before_start1529=== PAUSE TestParseSingleRange/malformed_end_before_start1530=== RUN TestParseSingleRange/closed1531=== PAUSE TestParseSingleRange/closed1532=== RUN TestParseSingleRange/open-ended1533=== PAUSE TestParseSingleRange/open-ended1534=== RUN TestParseSingleRange/end_clamped_to_size1535=== PAUSE TestParseSingleRange/end_clamped_to_size1536=== RUN TestParseSingleRange/suffix1537=== PAUSE TestParseSingleRange/suffix1538=== RUN TestParseSingleRange/suffix_exceeds_size1539=== PAUSE TestParseSingleRange/suffix_exceeds_size1540=== RUN TestParseSingleRange/single_byte1541=== PAUSE TestParseSingleRange/single_byte1542=== RUN TestParseSingleRange/start_past_EOF1543=== PAUSE TestParseSingleRange/start_past_EOF1544=== RUN TestParseSingleRange/start_far_past_EOF1545=== PAUSE TestParseSingleRange/start_far_past_EOF1546=== CONT TestReadProxyNarStreaming15472026/09/29 08:15:47 OK 2_object_stats_trigger.sql (5.18ms)15482026/09/29 08:15:47 OK 20251210153512_drop_unused_gin_index.sql (7.74ms)15492026/09/29 08:15:47 OK 3_commit_push.sql (2.4ms)15502026/09/29 08:15:47 goose: up to current file version: 315512026/09/29 08:15:47 OK 20251218171726_add_pins.sql (5.65ms)15522026/09/29 08:15:47 OK 20260628120000_add_object_size_and_stats.sql (7.28ms)15532026/09/29 08:15:47 OK 20260905000000_add_claims.sql (7.37ms)15542026/09/29 08:15:47 OK 20260920000000_drop_claims.sql (4.33ms)15552026/09/29 08:15:47 OK 20260923120000_add_pushes.sql (6.09ms)15562026/09/29 08:15:47 goose: successfully migrated database to version: 202609231200001557--- PASS: TestReadProxyInvalidPath (1.66s)1558=== CONT TestReadProxy40415592026/09/29 08:15:48 OK 1_commit_pending_closure.sql (41.26ms)15602026/09/29 08:15:48 OK 2_object_stats_trigger.sql (6.26ms)15612026/09/29 08:15:48 OK 3_commit_push.sql (9.55ms)15622026/09/29 08:15:48 goose: up to current file version: 315632026-09-29 08:15:48.037 UTC [671] ERROR: relation "goose_db_version" does not exist at character 3615642026-09-29 08:15:48.037 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15652026-09-29 08:15:48.038 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3615662026-09-29 08:15:48.038 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15672026-09-29 08:15:48.048 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3615682026-09-29 08:15:48.048 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/09/29 08:15:48 OK 20241026095416_initial_model.sql (11.36ms)15702026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (3.87ms)15712026/09/29 08:15:48 OK 20241026095416_initial_model.sql (11.2ms)15722026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)15732026/09/29 08:15:48 OK 20251218171726_add_pins.sql (4.85ms)15742026/09/29 08:15:48 OK 20241026095416_initial_model.sql (11.34ms)15752026/09/29 08:15:48 OK 20251218171726_add_pins.sql (4.32ms)15762026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (7.54ms)1577--- PASS: TestReadProxyDisabled (1.67s)1578=== CONT TestResurrectedObjectNotDeleted15792026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (16.78ms)15802026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (20.51ms)15812026/09/29 08:15:48 OK 20260905000000_add_claims.sql (18.59ms)15822026/09/29 08:15:48 OK 20251218171726_add_pins.sql (7.12ms)15832026/09/29 08:15:48 OK 20260905000000_add_claims.sql (8.48ms)15842026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (7.78ms)15852026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (11.99ms)15862026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (8.35ms)15872026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000015882026-09-29 08:15:48.113 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3615892026-09-29 08:15:48.113 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15902026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (18.9ms)15912026/09/29 08:15:48 OK 1_commit_pending_closure.sql (7.4ms)15922026/09/29 08:15:48 OK 20260905000000_add_claims.sql (4.32ms)15932026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (10.38ms)15942026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000015952026/09/29 08:15:48 OK 2_object_stats_trigger.sql (4.54ms)15962026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (6.05ms)15972026/09/29 08:15:48 OK 1_commit_pending_closure.sql (6.14ms)15982026/09/29 08:15:48 OK 3_commit_push.sql (7.15ms)15992026/09/29 08:15:48 goose: up to current file version: 316002026/09/29 08:15:48 OK 2_object_stats_trigger.sql (5.17ms)16012026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (5.69ms)16022026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016032026/09/29 08:15:48 OK 3_commit_push.sql (4.4ms)16042026/09/29 08:15:48 goose: up to current file version: 316052026/09/29 08:15:48 OK 1_commit_pending_closure.sql (7.05ms)16062026/09/29 08:15:48 OK 20241026095416_initial_model.sql (16.33ms)16072026/09/29 08:15:48 OK 2_object_stats_trigger.sql (1.98ms)16082026/09/29 08:15:48 OK 3_commit_push.sql (5.1ms)16092026/09/29 08:15:48 goose: up to current file version: 316102026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (6.71ms)16112026/09/29 08:15:48 OK 20251218171726_add_pins.sql (8.5ms)1612--- PASS: TestReadRedirectNar (1.83s)1613=== CONT TestClientFallsBackToClosures16142026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (11.02ms)16152026/09/29 08:15:48 OK 20260905000000_add_claims.sql (3.87ms)16162026-09-29 08:15:48.172 UTC [678] ERROR: relation "goose_db_version" does not exist at character 3616172026-09-29 08:15:48.172 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16182026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (2.85ms)16192026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (4.12ms)16202026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016212026/09/29 08:15:48 OK 1_commit_pending_closure.sql (5.69ms)16222026/09/29 08:15:48 OK 2_object_stats_trigger.sql (5.81ms)16232026/09/29 08:15:48 OK 20241026095416_initial_model.sql (12.06ms)16242026/09/29 08:15:48 OK 3_commit_push.sql (4.51ms)16252026/09/29 08:15:48 goose: up to current file version: 316262026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)1627--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.39s)1628=== CONT TestGCBugBareHashReferences16292026/09/29 08:15:48 OK 20251218171726_add_pins.sql (7ms)16302026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (6.39ms)16312026/09/29 08:15:48 OK 20260905000000_add_claims.sql (3.87ms)16322026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (22.35ms)16332026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (7.96ms)16342026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016352026/09/29 08:15:48 OK 1_commit_pending_closure.sql (4.49ms)16362026/09/29 08:15:48 OK 2_object_stats_trigger.sql (2.81ms)1637--- PASS: TestReadProxyConditionalGet (1.28s)1638=== CONT TestLeadEndsOnShutdown16392026/09/29 08:15:48 OK 3_commit_push.sql (2.49ms)16402026/09/29 08:15:48 goose: up to current file version: 316412026-09-29 08:15:48.255 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3616422026-09-29 08:15:48.255 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16432026/09/29 08:15:48 OK 20241026095416_initial_model.sql (17.34ms)16442026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)16452026-09-29 08:15:48.290 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3616462026-09-29 08:15:48.290 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16472026/09/29 08:15:48 OK 20251218171726_add_pins.sql (5.86ms)1648--- PASS: TestReadProxyHead (1.21s)1649=== CONT TestLeadElectsOneAndHandsOver16502026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (6.78ms)16512026/09/29 08:15:48 OK 20260905000000_add_claims.sql (5.65ms)16522026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (5.81ms)16532026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (3.96ms)16542026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016552026/09/29 08:15:48 OK 20241026095416_initial_model.sql (12.16ms)16562026/09/29 08:15:48 OK 1_commit_pending_closure.sql (3.35ms)16572026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)16582026/09/29 08:15:48 OK 2_object_stats_trigger.sql (2.19ms)16592026/09/29 08:15:48 OK 3_commit_push.sql (2.68ms)16602026/09/29 08:15:48 goose: up to current file version: 316612026/09/29 08:15:48 OK 20251218171726_add_pins.sql (4.86ms)16622026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (6.13ms)16632026/09/29 08:15:48 INFO Received uploads request method=POST path=/api/pending_closures16642026/09/29 08:15:48 OK 20260905000000_add_claims.sql (7.07ms)16652026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (4.31ms)16662026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (2.57ms)16672026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016682026-09-29 08:15:48.346 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3616692026-09-29 08:15:48.346 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16702026/09/29 08:15:48 OK 1_commit_pending_closure.sql (4.16ms)16712026/09/29 08:15:48 OK 2_object_stats_trigger.sql (3.45ms)16722026/09/29 08:15:48 OK 3_commit_push.sql (4.73ms)16732026/09/29 08:15:48 goose: up to current file version: 316742026/09/29 08:15:48 OK 20241026095416_initial_model.sql (16.58ms)16752026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)16762026/09/29 08:15:48 OK 20251218171726_add_pins.sql (6.95ms)16772026-09-29 08:15:48.384 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3616782026-09-29 08:15:48.384 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16792026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (10.95ms)16802026/09/29 08:15:48 OK 20260905000000_add_claims.sql (8.86ms)16812026/09/29 08:15:48 OK 20241026095416_initial_model.sql (10.49ms)16822026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)16832026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (4.72ms)16842026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (3.62ms)16852026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016862026/09/29 08:15:48 OK 20251218171726_add_pins.sql (5.82ms)16872026/09/29 08:15:48 OK 1_commit_pending_closure.sql (5.43ms)16882026/09/29 08:15:48 INFO Received uploads request method=POST path=/api/pending_closures16892026/09/29 08:15:48 OK 2_object_stats_trigger.sql (3.29ms)16902026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (7.25ms)16912026/09/29 08:15:48 OK 3_commit_push.sql (4.35ms)16922026/09/29 08:15:48 goose: up to current file version: 316932026/09/29 08:15:48 OK 20260905000000_add_claims.sql (10.39ms)16942026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (8.74ms)16952026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (7.75ms)16962026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000016972026/09/29 08:15:48 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16982026/09/29 08:15:48 INFO Received uploads request method=POST path=/api/pending_closures16992026/09/29 08:15:48 OK 1_commit_pending_closure.sql (9.17ms)1700--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.30s)1701=== CONT TestResolveDBConnectionString1702=== RUN TestResolveDBConnectionString/flag_wins1703=== PAUSE TestResolveDBConnectionString/flag_wins1704=== RUN TestResolveDBConnectionString/file_when_flag_empty1705=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1706=== RUN TestResolveDBConnectionString/missing_file_is_an_error1707=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1708=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1709=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1710=== RUN TestResolveDBConnectionString/nothing_configured1711=== PAUSE TestResolveDBConnectionString/nothing_configured1712=== CONT TestOrphanedObjectsGCStressTest17132026/09/29 08:15:48 OK 2_object_stats_trigger.sql (6.15ms)17142026/09/29 08:15:48 OK 3_commit_push.sql (5.78ms)17152026/09/29 08:15:48 goose: up to current file version: 31716--- PASS: TestService_Rustfstest (1.35s)1717=== CONT TestPush_RejectsBadRequests17182026-09-29 08:15:48.548 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3617192026-09-29 08:15:48.548 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1720--- PASS: TestService_ReadScope_PublicByDefault (1.30s)1721=== CONT TestClientSharedPathCommittedMidPush17222026/09/29 08:15:48 OK 20241026095416_initial_model.sql (15.65ms)17232026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)17242026/09/29 08:15:48 OK 20251218171726_add_pins.sql (3.6ms)17252026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (6.71ms)17262026/09/29 08:15:48 OK 20260905000000_add_claims.sql (5.91ms)17272026-09-29 08:15:48.597 UTC [696] ERROR: relation "goose_db_version" does not exist at character 3617282026-09-29 08:15:48.597 UTC [696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17292026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (3.47ms)17302026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (3.56ms)17312026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000017322026/09/29 08:15:48 OK 1_commit_pending_closure.sql (5.25ms)17332026/09/29 08:15:48 OK 2_object_stats_trigger.sql (4.47ms)17342026/09/29 08:15:48 OK 3_commit_push.sql (3.5ms)17352026/09/29 08:15:48 goose: up to current file version: 317362026/09/29 08:15:48 OK 20241026095416_initial_model.sql (20.49ms)17372026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (3.86ms)17382026/09/29 08:15:48 OK 20251218171726_add_pins.sql (3.89ms)17392026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)17402026/09/29 08:15:48 OK 20260905000000_add_claims.sql (3.83ms)17412026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (3.01ms)17422026-09-29 08:15:48.647 UTC [698] ERROR: relation "goose_db_version" does not exist at character 3617432026-09-29 08:15:48.647 UTC [698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17442026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (3.98ms)17452026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000017462026/09/29 08:15:48 OK 1_commit_pending_closure.sql (2.81ms)17472026/09/29 08:15:48 OK 2_object_stats_trigger.sql (1.55ms)17482026/09/29 08:15:48 OK 3_commit_push.sql (2ms)17492026/09/29 08:15:48 goose: up to current file version: 317502026/09/29 08:15:48 OK 20241026095416_initial_model.sql (12.44ms)17512026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)17522026/09/29 08:15:48 OK 20251218171726_add_pins.sql (3.85ms)17532026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (7.16ms)17542026/09/29 08:15:48 OK 20260905000000_add_claims.sql (8.62ms)17552026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (5.51ms)1756--- PASS: TestCacheStatsHandler (1.32s)1757=== CONT TestClientPushesUseOnePush17582026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (2.73ms)17592026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000017602026/09/29 08:15:48 OK 1_commit_pending_closure.sql (4.2ms)17612026/09/29 08:15:48 OK 2_object_stats_trigger.sql (1.78ms)17622026/09/29 08:15:48 OK 3_commit_push.sql (1.77ms)17632026/09/29 08:15:48 goose: up to current file version: 31764=== NAME TestClientCADerivations1765 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3819916797/001/store/y5bw0a2mqgvhkvcq9pdg8ngarkla3ldv-ca-test17662026/09/29 08:15:48 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17672026/09/29 08:15:48 WARN mTLS auth: bound subjects configured but subject DN unavailable17682026/09/29 08:15:48 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1769--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.30s)1770=== CONT TestPinProtectsFromGC1771=== NAME TestClientCADerivations1772 client_ca_test.go:139: Found 1 dependencies (including self)17732026-09-29 08:15:48.786 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3617742026-09-29 08:15:48.786 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1775=== RUN TestService_RequireScope_OIDC/builder_may_write1776=== PAUSE TestService_RequireScope_OIDC/builder_may_write1777=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1778=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1779=== RUN TestService_RequireScope_OIDC/ops_may_admin1780=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1781=== RUN TestService_RequireScope_OIDC/ops_may_not_write1782=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1783=== RUN TestService_RequireScope_OIDC/reader_may_not_write1784=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1785=== RUN TestService_RequireScope_OIDC/static_token_may_admin1786=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1787=== RUN TestService_RequireScope_OIDC/static_token_may_write1788=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1789=== RUN TestService_RequireScope_OIDC/reader_may_read1790=== PAUSE TestService_RequireScope_OIDC/reader_may_read1791=== RUN TestService_RequireScope_OIDC/writer_implies_read1792=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1793=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1794=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1795=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected17962026/09/29 08:15:48 OK 20241026095416_initial_model.sql (13.59ms)17972026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)17982026/09/29 08:15:48 OK 20251218171726_add_pins.sql (3.6ms)17992026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)18002026-09-29 08:15:48.819 UTC [776] ERROR: relation "goose_db_version" does not exist at character 3618012026-09-29 08:15:48.819 UTC [776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1802--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.23s)1803=== CONT TestReadProxyNarinfoAlreadyDecompressed18042026/09/29 08:15:48 OK 20260905000000_add_claims.sql (7.48ms)18052026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (3.68ms)18062026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (2.56ms)18072026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000018082026/09/29 08:15:48 OK 1_commit_pending_closure.sql (2.55ms)18092026/09/29 08:15:48 OK 2_object_stats_trigger.sql (2.56ms)18102026/09/29 08:15:48 OK 20241026095416_initial_model.sql (10.05ms)18112026/09/29 08:15:48 OK 3_commit_push.sql (4.28ms)18122026/09/29 08:15:48 goose: up to current file version: 318132026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)18142026/09/29 08:15:48 OK 20251218171726_add_pins.sql (5.18ms)18152026/09/29 08:15:48 INFO Received push request method=POST path=/api/pushes18162026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (6.27ms)18172026/09/29 08:15:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18182026/09/29 08:15:48 OK 20260905000000_add_claims.sql (5.18ms)18192026/09/29 08:15:48 INFO Uploading y5bw0a2mqgvhkvcq9pdg8ngarkla3ldv-ca-test (144B)18202026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (3.62ms)18212026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (3.11ms)18222026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000018232026/09/29 08:15:48 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18242026/09/29 08:15:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18252026/09/29 08:15:48 WARN Failed to register uploaded object key=y5bw0a2mqgvhkvcq9pdg8ngarkla3ldv.ls error="server returned 404: 404 page not found\n"18262026/09/29 08:15:48 WARN Failed to register uploaded object key=log/0nvdx7bf7jcf1l9wv9qm85snpia9hy3s-ca-test.drv error="server returned 404: 404 page not found\n"1827--- PASS: TestService_ReadAuthMiddleware (1.22s)1828=== CONT TestClientWithDependencies18292026/09/29 08:15:48 INFO Signed narinfos id=1 count=118302026/09/29 08:15:48 INFO Uploading 1 narinfos18312026/09/29 08:15:48 OK 1_commit_pending_closure.sql (2.59ms)18322026/09/29 08:15:48 OK 2_object_stats_trigger.sql (1.62ms)18332026/09/29 08:15:48 OK 3_commit_push.sql (1.23ms)18342026/09/29 08:15:48 goose: up to current file version: 318352026/09/29 08:15:48 INFO Received complete push request method=POST path=/api/pushes/1/complete18362026/09/29 08:15:48 WARN Failed to register uploaded object key=y5bw0a2mqgvhkvcq9pdg8ngarkla3ldv.narinfo error="server returned 404: 404 page not found\n"18372026-09-29 08:15:48.877 UTC [815] ERROR: relation "goose_db_version" does not exist at character 3618382026-09-29 08:15:48.877 UTC [815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18392026/09/29 08:15:48 INFO Upload complete. (97ms)1840=== NAME TestClientCADerivations1841 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3819916797/001/store/y5bw0a2mqgvhkvcq9pdg8ngarkla3ldv-ca-test1842 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1843 Compression: zstd1844 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1845 NarSize: 1441846 References: 1847 Deriver: /build/TestClientCADerivations3819916797/001/store/0nvdx7bf7jcf1l9wv9qm85snpia9hy3s-ca-test.drv1848 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1849 client_ca_test.go:185: Checking for realisation files in S3...1850 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1851 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1852=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1853=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1854=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1855=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1856=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1857=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1858=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1859=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1860=== CONT TestReadProxyNarinfo18612026/09/29 08:15:48 OK 20241026095416_initial_model.sql (13.33ms)18622026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)18632026/09/29 08:15:48 OK 20251218171726_add_pins.sql (3.32ms)18642026-09-29 08:15:48.905 UTC [820] ERROR: relation "goose_db_version" does not exist at character 3618652026-09-29 08:15:48.905 UTC [820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18662026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (9.5ms)18672026/09/29 08:15:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18682026/09/29 08:15:48 OK 20260905000000_add_claims.sql (3.87ms)18692026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (2.72ms)18702026/09/29 08:15:48 INFO Received push request method=POST path=/api/pushes18712026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (2.43ms)18722026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000018732026/09/29 08:15:48 OK 1_commit_pending_closure.sql (2.97ms)18742026/09/29 08:15:48 OK 20241026095416_initial_model.sql (11.44ms)18752026/09/29 08:15:48 OK 2_object_stats_trigger.sql (1.86ms)18762026/09/29 08:15:48 OK 3_commit_push.sql (2.59ms)18772026/09/29 08:15:48 goose: up to current file version: 318782026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (3.84ms)18792026/09/29 08:15:48 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDAyYWI3NjgtNzBhZi00NDRlLTlmNTctMTZlZmMzYTdiMGQ5LjYwNTllNWI2LTgyNGMtNDk2OC04OWE1LWE3MmYwZTQ0NDRiN3gxNzkwNjY5NzQ4MzQ3MTM2Mjc2 parts=1218802026/09/29 08:15:48 INFO Received uploads request method=POST path=/api/pending_closures18812026/09/29 08:15:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18822026/09/29 08:15:48 OK 20251218171726_add_pins.sql (6.35ms)18832026/09/29 08:15:48 INFO Signed narinfos id=1 count=11884--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.20s)1885=== CONT TestClientMultipleUploads1886--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.80s)1887=== CONT TestClientIntegration18882026-09-29 08:15:48.943 UTC [839] ERROR: relation "goose_db_version" does not exist at character 3618892026-09-29 08:15:48.943 UTC [839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18902026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (12.18ms)18912026/09/29 08:15:48 OK 20260905000000_add_claims.sql (8.56ms)18922026/09/29 08:15:48 OK 20260920000000_drop_claims.sql (5.88ms)18932026/09/29 08:15:48 OK 20241026095416_initial_model.sql (14.42ms)18942026/09/29 08:15:48 OK 20260923120000_add_pushes.sql (7.09ms)18952026/09/29 08:15:48 goose: successfully migrated database to version: 2026092312000018962026/09/29 08:15:48 OK 20251210153512_drop_unused_gin_index.sql (6.7ms)18972026/09/29 08:15:48 INFO Received uploads request method=POST path=/api/pending_closures18982026/09/29 08:15:48 OK 1_commit_pending_closure.sql (6.96ms)18992026-09-29 08:15:48.979 UTC [904] ERROR: relation "goose_db_version" does not exist at character 3619002026-09-29 08:15:48.979 UTC [904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19012026/09/29 08:15:48 OK 20251218171726_add_pins.sql (6.82ms)19022026/09/29 08:15:48 OK 2_object_stats_trigger.sql (8.74ms)19032026/09/29 08:15:48 OK 20260628120000_add_object_size_and_stats.sql (8.76ms)19042026/09/29 08:15:48 OK 3_commit_push.sql (7.28ms)19052026/09/29 08:15:48 goose: up to current file version: 319062026/09/29 08:15:48 OK 20260905000000_add_claims.sql (8.59ms)19072026/09/29 08:15:49 OK 20260920000000_drop_claims.sql (5.58ms)1908=== NAME TestClientCADerivations1909 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1910 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1911 error: binary cache 's3://bucket34?endpoint=http://localhost:33351®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3819916797/001/store'1912 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119132026/09/29 08:15:49 OK 20241026095416_initial_model.sql (15.06ms)19142026/09/29 08:15:49 OK 20260923120000_add_pushes.sql (3.05ms)19152026/09/29 08:15:49 goose: successfully migrated database to version: 202609231200001916--- PASS: TestClientCADerivations (1.72s)1917=== CONT TestIsValidCachePath1918=== RUN TestIsValidCachePath/narinfo1919=== PAUSE TestIsValidCachePath/narinfo1920=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1921=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1922=== RUN TestIsValidCachePath/nar_zst1923=== PAUSE TestIsValidCachePath/nar_zst1924=== RUN TestIsValidCachePath/nar_xz1925=== PAUSE TestIsValidCachePath/nar_xz1926=== RUN TestIsValidCachePath/nar_bz21927=== PAUSE TestIsValidCachePath/nar_bz21928=== RUN TestIsValidCachePath/nar_uncompressed1929=== PAUSE TestIsValidCachePath/nar_uncompressed1930=== RUN TestIsValidCachePath/ls1931=== PAUSE TestIsValidCachePath/ls1932=== RUN TestIsValidCachePath/log1933=== PAUSE TestIsValidCachePath/log1934=== RUN TestIsValidCachePath/realisation1935=== PAUSE TestIsValidCachePath/realisation1936=== RUN TestIsValidCachePath/nix-cache-info1937=== PAUSE TestIsValidCachePath/nix-cache-info1938=== RUN TestIsValidCachePath/index.html1939=== PAUSE TestIsValidCachePath/index.html1940=== RUN TestIsValidCachePath/traversal_parent1941=== PAUSE TestIsValidCachePath/traversal_parent1942=== RUN TestIsValidCachePath/traversal_in_middle1943=== PAUSE TestIsValidCachePath/traversal_in_middle1944=== RUN TestIsValidCachePath/invalid_char_e1945=== PAUSE TestIsValidCachePath/invalid_char_e1946=== RUN TestIsValidCachePath/invalid_char_u1947=== PAUSE TestIsValidCachePath/invalid_char_u1948=== RUN TestIsValidCachePath/random_path1949=== PAUSE TestIsValidCachePath/random_path1950=== RUN TestIsValidCachePath/empty1951=== PAUSE TestIsValidCachePath/empty1952=== RUN TestIsValidCachePath/leading_slash1953=== PAUSE TestIsValidCachePath/leading_slash1954=== RUN TestIsValidCachePath/wrong_extension1955=== PAUSE TestIsValidCachePath/wrong_extension1956=== RUN TestIsValidCachePath/short_hash1957=== PAUSE TestIsValidCachePath/short_hash1958=== CONT TestServerTLSConfig/no_client_CA1959=== CONT TestServerTLSConfig/not_a_PEM_file19602026/09/29 08:15:49 OK 20251210153512_drop_unused_gin_index.sql (3.53ms)1961=== CONT TestServerTLSConfig/missing_CA_file1962--- PASS: TestServerTLSConfig (0.00s)1963 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1964 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1965 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1966=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19672026/09/29 08:15:49 INFO Received uploads request method=POST path=/1968=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19692026/09/29 08:15:49 INFO Received request for more parts method=POST path=/1970=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19712026/09/29 08:15:49 INFO Received complete multipart upload request method=POST path=/1972=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19732026/09/29 08:15:49 INFO Received uploads request method=POST path=/1974--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1975 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1976 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1977 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1978 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1979=== CONT TestProxyWriteTimeout/narinfo1980=== CONT TestProxyWriteTimeout/10_GiB_nar1981=== CONT TestProxyWriteTimeout/unknown_size1982=== CONT TestProxyWriteTimeout/1_GiB_nar1983--- PASS: TestProxyWriteTimeout (0.06s)1984 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1985 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1986 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1987 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1988=== CONT TestIsValidUploadKey/narinfo1989=== CONT TestIsValidUploadKey/realisation_plus_in_output1990=== CONT TestIsValidUploadKey/unknown_type1991=== CONT TestIsValidUploadKey/empty_key1992=== CONT TestIsValidUploadKey/absolute1993=== CONT TestIsValidUploadKey/traversal_nar1994=== CONT TestIsValidUploadKey/traversal1995=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1996=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1997=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1998=== CONT TestIsValidUploadKey/index.html1999=== CONT TestIsValidUploadKey/nix-cache-info2000=== CONT TestIsValidUploadKey/build_log_home-manager_file2001=== CONT TestIsValidUploadKey/realisation2002=== CONT TestIsValidUploadKey/build_log_equals2003=== CONT TestIsValidUploadKey/build_log_question_mark2004=== CONT TestIsValidUploadKey/build_log_plus_in_name20052026/09/29 08:15:49 OK 1_commit_pending_closure.sql (5.76ms)2006=== CONT TestIsValidUploadKey/nar_plain2007=== CONT TestIsValidUploadKey/listing2008=== CONT TestIsValidUploadKey/nar_xz2009=== CONT TestIsValidUploadKey/nar_zst2010=== CONT TestIsValidUploadKey/build_log2011--- PASS: TestIsValidUploadKey (0.06s)2012 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2013 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2014 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2015 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2016 --- PASS: TestIsValidUploadKey/absolute (0.00s)2017 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2018 --- PASS: TestIsValidUploadKey/traversal (0.00s)2019 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2020 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2021 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2022 --- PASS: TestIsValidUploadKey/index.html (0.00s)2023 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2024 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2025 --- PASS: TestIsValidUploadKey/realisation (0.00s)2026 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2027 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2028 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2029 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2030 --- PASS: TestIsValidUploadKey/listing (0.00s)2031 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2032 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2033 --- PASS: TestIsValidUploadKey/build_log (0.00s)20342026/09/29 08:15:49 OK 20251218171726_add_pins.sql (5.7ms)2035=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20362026/09/29 08:15:49 INFO Received uploads request method=POST path=/20372026/09/29 08:15:49 OK 2_object_stats_trigger.sql (2.01ms)20382026/09/29 08:15:49 OK 3_commit_push.sql (1.54ms)20392026/09/29 08:15:49 goose: up to current file version: 320402026/09/29 08:15:49 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)20412026/09/29 08:15:49 OK 20260905000000_add_claims.sql (3.96ms)20422026/09/29 08:15:49 INFO Received uploads request method=POST path=/api/pending_closures20432026/09/29 08:15:49 OK 20260920000000_drop_claims.sql (3.04ms)20442026/09/29 08:15:49 OK 20260923120000_add_pushes.sql (7.72ms)20452026/09/29 08:15:49 goose: successfully migrated database to version: 2026092312000020462026/09/29 08:15:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20472026/09/29 08:15:49 OK 1_commit_pending_closure.sql (2.16ms)20482026-09-29 08:15:49.037 UTC [942] ERROR: relation "goose_db_version" does not exist at character 3620492026-09-29 08:15:49.037 UTC [942] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20502026/09/29 08:15:49 OK 2_object_stats_trigger.sql (1.07ms)20512026/09/29 08:15:49 OK 3_commit_push.sql (777.53µs)20522026/09/29 08:15:49 goose: up to current file version: 320532026/09/29 08:15:49 INFO Received uploads request method=POST path=/api/pending_closures20542026/09/29 08:15:49 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDAyYWI3NjgtNzBhZi00NDRlLTlmNTctMTZlZmMzYTdiMGQ5Ljk1NGU1NDEyLTY4ZjEtNDg1NS05YTdkLTVhNjk4YjllODU5ZXgxNzkwNjY5NzQ4OTkxNzU5NDE520552026/09/29 08:15:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDAyYWI3NjgtNzBhZi00NDRlLTlmNTctMTZlZmMzYTdiMGQ5Ljk1NGU1NDEyLTY4ZjEtNDg1NS05YTdkLTVhNjk4YjllODU5ZXgxNzkwNjY5NzQ4OTkxNzU5NDE5 parts=12056--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.26s)2057=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20582026/09/29 08:15:49 INFO Received request for more parts method=POST path=/20592026-09-29 08:15:49.047 UTC [943] ERROR: relation "goose_db_version" does not exist at character 3620602026-09-29 08:15:49.047 UTC [943] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20612026/09/29 08:15:49 OK 20241026095416_initial_model.sql (9.53ms)20622026/09/29 08:15:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20632026/09/29 08:15:49 WARN Refused reserved pin name=worker-x86_64-linux20642026/09/29 08:15:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20652026/09/29 08:15:49 INFO Received create pin request method=POST path=/api/pins/my-app20662026/09/29 08:15:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2067--- PASS: TestCreatePin_ReservedPins (1.24s)2068=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20692026/09/29 08:15:49 INFO Received complete multipart upload request method=POST path=/20702026/09/29 08:15:49 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)20712026/09/29 08:15:49 OK 20251218171726_add_pins.sql (3.41ms)20722026/09/29 08:15:49 OK 20241026095416_initial_model.sql (8.68ms)20732026/09/29 08:15:49 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)20742026/09/29 08:15:49 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)20752026/09/29 08:15:49 OK 20260905000000_add_claims.sql (3.38ms)20762026/09/29 08:15:49 OK 20251218171726_add_pins.sql (3.23ms)20772026/09/29 08:15:49 OK 20260920000000_drop_claims.sql (2.64ms)20782026/09/29 08:15:49 OK 20260923120000_add_pushes.sql (2.09ms)20792026/09/29 08:15:49 goose: successfully migrated database to version: 2026092312000020802026/09/29 08:15:49 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)20812026/09/29 08:15:49 OK 1_commit_pending_closure.sql (2.31ms)20822026/09/29 08:15:49 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1818457883/001/proxy.sock20832026/09/29 08:15:49 INFO Starting HTTP server address=127.0.0.1:3394120842026/09/29 08:15:49 WARN mTLS auth: subject not in bound subjects subject="CN=someone"20852026/09/29 08:15:49 OK 2_object_stats_trigger.sql (1.17ms)20862026/09/29 08:15:49 INFO Shutdown signal received, draining in-flight requests timeout=10s2087--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.17s)2088=== CONT TestClientErrorHandling/InvalidStorePath20892026/09/29 08:15:49 OK 20260905000000_add_claims.sql (4.53ms)20902026/09/29 08:15:49 OK 3_commit_push.sql (1.95ms)20912026/09/29 08:15:49 goose: up to current file version: 320922026/09/29 08:15:49 OK 20260920000000_drop_claims.sql (2.34ms)20932026/09/29 08:15:49 OK 20260923120000_add_pushes.sql (2.29ms)20942026/09/29 08:15:49 goose: successfully migrated database to version: 2026092312000020952026/09/29 08:15:49 OK 1_commit_pending_closure.sql (1.96ms)20962026/09/29 08:15:49 OK 2_object_stats_trigger.sql (797.85µs)20972026/09/29 08:15:49 OK 3_commit_push.sql (751.11µs)20982026/09/29 08:15:49 goose: up to current file version: 32099=== CONT TestClientErrorHandling/ServerNotAvailable2100=== CONT TestClientErrorHandling/InvalidAuthToken2101--- PASS: TestReadProxyNarStreaming (1.17s)2102=== CONT TestCacheConfigHandler/full_config,_no_issuer2103=== CONT TestCacheConfigHandler/no_signing_keys2104=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2105=== CONT TestCacheConfigHandler/no_cache_url_configured2106--- PASS: TestCacheConfigHandler (0.00s)2107 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2108 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2109 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2110 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2111=== CONT TestParseSingleRange/none2112=== CONT TestParseSingleRange/open-ended2113=== CONT TestParseSingleRange/start_far_past_EOF2114=== CONT TestParseSingleRange/start_past_EOF2115=== CONT TestParseSingleRange/single_byte2116=== CONT TestParseSingleRange/suffix_exceeds_size2117=== CONT TestParseSingleRange/suffix2118=== CONT TestParseSingleRange/end_clamped_to_size2119=== CONT TestParseSingleRange/malformed_both_empty2120=== CONT TestParseSingleRange/closed2121=== CONT TestParseSingleRange/malformed_end_before_start2122=== CONT TestParseSingleRange/multi-range_ignored2123=== CONT TestParseSingleRange/malformed_no_dash2124=== CONT TestParseSingleRange/unknown_unit2125--- PASS: TestParseSingleRange (0.00s)2126 --- PASS: TestParseSingleRange/none (0.00s)2127 --- PASS: TestParseSingleRange/open-ended (0.00s)2128 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2129 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2130 --- PASS: TestParseSingleRange/single_byte (0.00s)2131 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2132 --- PASS: TestParseSingleRange/suffix (0.00s)2133 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2134 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2135 --- PASS: TestParseSingleRange/closed (0.00s)2136 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2137 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2138 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2139 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2140=== CONT TestResolveDBConnectionString/flag_wins2141=== CONT TestResolveDBConnectionString/missing_file_is_an_error2142=== CONT TestResolveDBConnectionString/nothing_configured2143=== CONT TestResolveDBConnectionString/file_when_flag_empty2144=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2145=== CONT TestService_RequireScope_OIDC/builder_may_write2146--- PASS: TestResolveDBConnectionString (0.00s)2147 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2148 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2149 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2150 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2151 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2152=== CONT TestService_RequireScope_OIDC/static_token_may_admin2153=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2154=== CONT TestService_RequireScope_OIDC/writer_implies_read2155=== CONT TestService_RequireScope_OIDC/reader_may_read2156=== CONT TestService_RequireScope_OIDC/static_token_may_write2157=== CONT TestService_RequireScope_OIDC/ops_may_not_write2158=== CONT TestService_RequireScope_OIDC/reader_may_not_write2159=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2160=== CONT TestService_RequireScope_OIDC/ops_may_admin2161=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2162--- PASS: TestService_RequireScope_OIDC (1.38s)2163 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2164 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2165 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2166 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2167 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2168 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2169 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2170 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2171 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2172 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2173=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21742026/09/29 08:15:49 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2175=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2176=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21772026/09/29 08:15:49 WARN Authentication failed token_preview=eyJhbGciOi...2JcvvuOXSg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2178=== CONT TestIsValidCachePath/narinfo2179=== CONT TestIsValidCachePath/short_hash2180=== CONT TestIsValidCachePath/wrong_extension2181=== CONT TestIsValidCachePath/leading_slash2182=== CONT TestIsValidCachePath/empty2183=== CONT TestIsValidCachePath/random_path2184=== CONT TestIsValidCachePath/invalid_char_u2185=== CONT TestIsValidCachePath/invalid_char_e2186=== CONT TestIsValidCachePath/traversal_in_middle2187=== CONT TestIsValidCachePath/traversal_parent2188=== CONT TestIsValidCachePath/index.html2189=== CONT TestIsValidCachePath/nix-cache-info2190=== CONT TestIsValidCachePath/realisation2191=== CONT TestIsValidCachePath/log2192=== CONT TestIsValidCachePath/ls2193=== CONT TestIsValidCachePath/nar_uncompressed2194=== CONT TestIsValidCachePath/nar_bz22195=== CONT TestIsValidCachePath/nar_xz2196=== CONT TestIsValidCachePath/nar_zst2197=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2198--- PASS: TestIsValidCachePath (0.00s)2199 --- PASS: TestIsValidCachePath/narinfo (0.00s)2200 --- PASS: TestIsValidCachePath/short_hash (0.00s)2201 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2202 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2203 --- PASS: TestIsValidCachePath/empty (0.00s)2204 --- PASS: TestIsValidCachePath/random_path (0.00s)2205 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2206 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2207 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2208 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2209 --- PASS: TestIsValidCachePath/index.html (0.00s)2210 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2211 --- PASS: TestIsValidCachePath/realisation (0.00s)2212 --- PASS: TestIsValidCachePath/log (0.00s)2213 --- PASS: TestIsValidCachePath/ls (0.00s)2214 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2215 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2216 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2217 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2218 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2219--- PASS: TestService_AuthMiddleware_OIDC (1.35s)2220 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2221 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2222 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2223 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2224--- PASS: TestReadProxy404 (1.14s)22252026-09-29 08:15:49.157 UTC [966] ERROR: relation "goose_db_version" does not exist at character 3622262026-09-29 08:15:49.157 UTC [966] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22272026/09/29 08:15:49 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/present22282026-09-29 08:15:49.172 UTC [984] ERROR: relation "goose_db_version" does not exist at character 3622292026-09-29 08:15:49.172 UTC [984] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22302026/09/29 08:15:49 OK 20241026095416_initial_model.sql (9.36ms)22312026/09/29 08:15:49 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)22322026/09/29 08:15:49 OK 20251218171726_add_pins.sql (2.77ms)22332026/09/29 08:15:49 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)22342026/09/29 08:15:49 OK 20260905000000_add_claims.sql (4.88ms)22352026/09/29 08:15:49 OK 20241026095416_initial_model.sql (9.73ms)22362026/09/29 08:15:49 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)22372026/09/29 08:15:49 OK 20260920000000_drop_claims.sql (2.28ms)22382026/09/29 08:15:49 OK 20260923120000_add_pushes.sql (2.7ms)22392026/09/29 08:15:49 goose: successfully migrated database to version: 2026092312000022402026/09/29 08:15:49 OK 20251218171726_add_pins.sql (3.4ms)22412026/09/29 08:15:49 OK 1_commit_pending_closure.sql (2.23ms)22422026/09/29 08:15:49 OK 2_object_stats_trigger.sql (1.12ms)22432026/09/29 08:15:49 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)2244--- PASS: TestResurrectedObjectNotDeleted (1.12s)22452026/09/29 08:15:49 OK 3_commit_push.sql (1.31ms)22462026/09/29 08:15:49 goose: up to current file version: 322472026/09/29 08:15:49 OK 20260905000000_add_claims.sql (4.01ms)22482026/09/29 08:15:49 OK 20260920000000_drop_claims.sql (1.96ms)22492026/09/29 08:15:49 OK 20260923120000_add_pushes.sql (1.6ms)22502026/09/29 08:15:49 goose: successfully migrated database to version: 2026092312000022512026/09/29 08:15:49 OK 1_commit_pending_closure.sql (2.75ms)22522026/09/29 08:15:49 OK 2_object_stats_trigger.sql (1.74ms)22532026/09/29 08:15:49 OK 3_commit_push.sql (724.75µs)22542026/09/29 08:15:49 goose: up to current file version: 322552026/09/29 08:15:49 INFO lead: acquired remote=192.0.2.1:123422562026/09/29 08:15:49 INFO lead: released remote=192.0.2.1:12342257--- PASS: TestLeadEndsOnShutdown (0.99s)22582026/09/29 08:15:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.970219ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22592026/09/29 08:15:49 INFO lead: acquired remote=192.0.2.1:12342260=== RUN TestPush_RejectsBadRequests/no_roots2261=== PAUSE TestPush_RejectsBadRequests/no_roots2262=== RUN TestPush_RejectsBadRequests/no_objects2263=== PAUSE TestPush_RejectsBadRequests/no_objects2264=== RUN TestPush_RejectsBadRequests/bad_root2265=== PAUSE TestPush_RejectsBadRequests/bad_root2266=== RUN TestPush_RejectsBadRequests/root_not_in_objects2267=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2268=== CONT TestPush_RejectsBadRequests/no_roots2269=== CONT TestPush_RejectsBadRequests/bad_root22702026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes22712026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes2272=== CONT TestPush_RejectsBadRequests/no_objects22732026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes2274=== CONT TestPush_RejectsBadRequests/root_not_in_objects22752026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes2276--- PASS: TestPush_RejectsBadRequests (0.82s)2277 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2278 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2279 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2280 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)22812026/09/29 08:15:49 INFO Received uploads request method=POST path=/api/pending_closures22822026/09/29 08:15:49 INFO Received uploads request method=POST path=/api/pending_closures22832026/09/29 08:15:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22842026/09/29 08:15:49 INFO Uploading gjm0qvd9zn16ykysv14f0sblz84m8qfz-a (216B)22852026/09/29 08:15:49 INFO Uploading 5xshadq1ngjamlnp0wqcg58jc33yrnkk-shared-dep (136B)22862026/09/29 08:15:49 WARN Failed to register uploaded object key=fxpgqmm1z9ag7kbqcgdp9gnqmwdxa4sn.ls error="server returned 404: 404 page not found\n"22872026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22882026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/07hwaq8788hngyajqsr6aq82vgzijvd6cn7gdzljyq6yqq905bcw.nar.zst error="server returned 404: 404 page not found\n"22892026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22902026/09/29 08:15:49 WARN Failed to register uploaded object key=5xshadq1ngjamlnp0wqcg58jc33yrnkk.ls error="server returned 404: 404 page not found\n"22912026/09/29 08:15:49 WARN Failed to register uploaded object key=gjm0qvd9zn16ykysv14f0sblz84m8qfz.ls error="server returned 404: 404 page not found\n"22922026/09/29 08:15:49 INFO Signed narinfos id=1 count=222932026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22942026/09/29 08:15:49 INFO Signed narinfos id=2 count=222952026/09/29 08:15:49 INFO Uploading 4 narinfos22962026/09/29 08:15:49 WARN Failed to register uploaded object key=5xshadq1ngjamlnp0wqcg58jc33yrnkk.narinfo error="server returned 404: 404 page not found\n"22972026/09/29 08:15:49 WARN Failed to register uploaded object key=fxpgqmm1z9ag7kbqcgdp9gnqmwdxa4sn.narinfo error="server returned 404: 404 page not found\n"22982026/09/29 08:15:49 WARN Failed to register uploaded object key=gjm0qvd9zn16ykysv14f0sblz84m8qfz.narinfo error="server returned 404: 404 page not found\n"22992026/09/29 08:15:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23002026/09/29 08:15:49 WARN Failed to register uploaded object key=5xshadq1ngjamlnp0wqcg58jc33yrnkk.narinfo error="server returned 404: 404 page not found\n"23012026/09/29 08:15:49 INFO Completed upload id=123022026/09/29 08:15:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23032026/09/29 08:15:49 INFO Completed upload id=223042026/09/29 08:15:49 INFO Upload complete. (66ms)2305=== NAME TestClientFallsBackToClosures2306 client_pushes_test.go:112: Retrieved narinfo from S3:2307 StorePath: /build/TestClientFallsBackToClosures853098154/001/store/5xshadq1ngjamlnp0wqcg58jc33yrnkk-shared-dep2308 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2309 Compression: zstd2310 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822311 NarSize: 1362312 References: 2313 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2314 client_pushes_test.go:112: Retrieved narinfo from S3:2315 StorePath: /build/TestClientFallsBackToClosures853098154/001/store/gjm0qvd9zn16ykysv14f0sblz84m8qfz-a2316 URL: nar/07hwaq8788hngyajqsr6aq82vgzijvd6cn7gdzljyq6yqq905bcw.nar.zst2317 Compression: zstd2318 NarHash: sha256:07hwaq8788hngyajqsr6aq82vgzijvd6cn7gdzljyq6yqq905bcw2319 NarSize: 2162320 References: /build/TestClientFallsBackToClosures853098154/001/store/5xshadq1ngjamlnp0wqcg58jc33yrnkk-shared-dep2321 CA: text:sha256:0zw994kixjf0jfjjymjgw31zs20wjw6cqqawmv8kgfrzkz0hzww623222026/09/29 08:15:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2323 client_pushes_test.go:112: Retrieved narinfo from S3:2324 StorePath: /build/TestClientFallsBackToClosures853098154/001/store/fxpgqmm1z9ag7kbqcgdp9gnqmwdxa4sn-b2325 URL: nar/07hwaq8788hngyajqsr6aq82vgzijvd6cn7gdzljyq6yqq905bcw.nar.zst2326 Compression: zstd2327 NarHash: sha256:07hwaq8788hngyajqsr6aq82vgzijvd6cn7gdzljyq6yqq905bcw2328 NarSize: 2162329 References: /build/TestClientFallsBackToClosures853098154/001/store/5xshadq1ngjamlnp0wqcg58jc33yrnkk-shared-dep2330 CA: text:sha256:0zw994kixjf0jfjjymjgw31zs20wjw6cqqawmv8kgfrzkz0hzww62331--- PASS: TestClientFallsBackToClosures (1.25s)23322026/09/29 08:15:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDAyYWI3NjgtNzBhZi00NDRlLTlmNTctMTZlZmMzYTdiMGQ5LmMzNTE4MzMxLTgwMmQtNGU1OC1iZmM2LWNhYmJkMjRlZTVlZngxNzkwNjY5NzQ5MDM2NDIwODQ1 parts=1223332026/09/29 08:15:49 INFO lead: released remote=192.0.2.1:12342334--- PASS: TestRedundantMultipartUpload (1.61s)23352026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes2336--- PASS: TestGCBugBareHashReferences (1.24s)23372026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete23382026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes2339--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.63s)23402026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/2/complete23412026/09/29 08:15:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.430259ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23422026-09-29 08:15:49.459 UTC [1144] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo23432026-09-29 08:15:49.459 UTC [1144] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE23442026-09-29 08:15:49.459 UTC [1144] STATEMENT: -- name: CommitPush :exec2345 SELECT commit_push($1::bigint)2346 2347--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.67s)2348=== NAME TestPinProtectsFromGC2349 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3355922326/001/store/d1bj6xmhs3fd74w52hvkhsmsp9mb9dkx-pinned-file.txt2350 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3355922326/001/store/04q36p1azlfj4cnldncpxhzqlvgnlmr6-unpinned-file.txt23512026/09/29 08:15:49 INFO lead: acquired remote=192.0.2.1:123423522026/09/29 08:15:49 INFO lead: released remote=192.0.2.1:12342353--- PASS: TestLeadElectsOneAndHandsOver (1.19s)23542026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes23552026/09/29 08:15:49 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)23562026/09/29 08:15:49 INFO Uploading b7nmj4iqdb7xm0yaqzpwnh4xmpnlb7kq-shared-dep (136B)23572026/09/29 08:15:49 INFO Uploading jy8c3l52k48ixzf19w7clhq97hb0f973-top (224B)23582026/09/29 08:15:49 WARN Failed to register uploaded object key=jy8c3l52k48ixzf19w7clhq97hb0f973.ls error="server returned 404: 404 page not found\n"23592026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23602026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1la85mi823imh8xi23rgf4mqpbqns4yhg78abqj2lbjcyixc7d8d.nar.zst error="server returned 404: 404 page not found\n"23612026/09/29 08:15:49 WARN Failed to register uploaded object key=b7nmj4iqdb7xm0yaqzpwnh4xmpnlb7kq.ls error="server returned 404: 404 page not found\n"23622026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23632026/09/29 08:15:49 INFO Signed narinfos id=1 count=223642026/09/29 08:15:49 INFO Uploading 2 narinfos23652026/09/29 08:15:49 WARN Failed to register uploaded object key=b7nmj4iqdb7xm0yaqzpwnh4xmpnlb7kq.narinfo error="server returned 404: 404 page not found\n"23662026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete23672026/09/29 08:15:49 WARN Failed to register uploaded object key=jy8c3l52k48ixzf19w7clhq97hb0f973.narinfo error="server returned 404: 404 page not found\n"2368--- PASS: TestReadProxyNarinfo (0.62s)23692026/09/29 08:15:49 INFO Upload complete. (59ms)2370=== NAME TestClientSharedPathCommittedMidPush2371 client_integration_test.go:680: Retrieved narinfo from S3:2372 StorePath: /build/TestClientSharedPathCommittedMidPush1803540067/001/store/b7nmj4iqdb7xm0yaqzpwnh4xmpnlb7kq-shared-dep2373 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2374 Compression: zstd2375 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822376 NarSize: 1362377 References: 2378 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2379 client_integration_test.go:680: Retrieved narinfo from S3:2380 StorePath: /build/TestClientSharedPathCommittedMidPush1803540067/001/store/jy8c3l52k48ixzf19w7clhq97hb0f973-top2381 URL: nar/1la85mi823imh8xi23rgf4mqpbqns4yhg78abqj2lbjcyixc7d8d.nar.zst2382 Compression: zstd2383 NarHash: sha256:1la85mi823imh8xi23rgf4mqpbqns4yhg78abqj2lbjcyixc7d8d2384 NarSize: 2242385 References: /build/TestClientSharedPathCommittedMidPush1803540067/001/store/b7nmj4iqdb7xm0yaqzpwnh4xmpnlb7kq-shared-dep2386 CA: text:sha256:1xkzsa6a2n447lyipvchdbnaqsdqb985qy2iyzghfib7izvrasvb2387--- PASS: TestClientSharedPathCommittedMidPush (0.96s)23882026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes23892026/09/29 08:15:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23902026/09/29 08:15:49 INFO Uploading d1bj6xmhs3fd74w52hvkhsmsp9mb9dkx-pinned-file.txt (128B)2391=== NAME TestClientWithDependencies2392 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2218379373/001/store/g6nc721ga6sk85yjbah2xhhxjifypwzm-test-script23932026/09/29 08:15:49 WARN Failed to register uploaded object key=d1bj6xmhs3fd74w52hvkhsmsp9mb9dkx.ls error="server returned 404: 404 page not found\n"23942026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23952026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"23962026/09/29 08:15:49 INFO Signed narinfos id=1 count=123972026/09/29 08:15:49 INFO Uploading 1 narinfos23982026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes23992026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete24002026/09/29 08:15:49 WARN Failed to register uploaded object key=d1bj6xmhs3fd74w52hvkhsmsp9mb9dkx.narinfo error="server returned 404: 404 page not found\n"24012026/09/29 08:15:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)24022026/09/29 08:15:49 INFO Uploading rf48pkr0d23a9iav80aqgf4v3hnnhlax-b (216B)24032026/09/29 08:15:49 INFO Uploading cdlj3riqbf4smp551nyjmapdaj0jpysr-shared-dep (136B)2404=== NAME TestClientIntegration2405 client_integration_test.go:286: Created store path: /build/TestClientIntegration3832674083/002/store/zkn7h1ysv46hdghr1nzcqjbrlzlpddqf-test-file.txt24062026/09/29 08:15:49 INFO Upload complete. (61ms)24072026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1krbi23l8caa1f7agxihz0aw0zvnanqj58cxgag86rhw9hqalhvs.nar.zst error="server returned 404: 404 page not found\n"24082026/09/29 08:15:49 WARN Failed to register uploaded object key=cdlj3riqbf4smp551nyjmapdaj0jpysr.ls error="server returned 404: 404 page not found\n"24092026/09/29 08:15:49 WARN Failed to register uploaded object key=hz1gp73aycdb1i2qg5khjmmfz7ckc73b.ls error="server returned 404: 404 page not found\n"24102026/09/29 08:15:49 WARN Failed to register uploaded object key=rf48pkr0d23a9iav80aqgf4v3hnnhlax.ls error="server returned 404: 404 page not found\n"24112026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24122026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24132026/09/29 08:15:49 INFO Signed narinfos id=1 count=324142026/09/29 08:15:49 INFO Uploading 3 narinfos24152026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete24162026/09/29 08:15:49 WARN Failed to register uploaded object key=hz1gp73aycdb1i2qg5khjmmfz7ckc73b.narinfo error="server returned 404: 404 page not found\n"24172026/09/29 08:15:49 WARN Failed to register uploaded object key=cdlj3riqbf4smp551nyjmapdaj0jpysr.narinfo error="server returned 404: 404 page not found\n"24182026/09/29 08:15:49 WARN Failed to register uploaded object key=rf48pkr0d23a9iav80aqgf4v3hnnhlax.narinfo error="server returned 404: 404 page not found\n"24192026/09/29 08:15:49 INFO Upload complete. (63ms)2420=== NAME TestClientPushesUseOnePush2421 client_pushes_test.go:97: Retrieved narinfo from S3:2422 StorePath: /build/TestClientPushesUseOnePush3328193807/001/store/cdlj3riqbf4smp551nyjmapdaj0jpysr-shared-dep2423 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2424 Compression: zstd2425 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822426 NarSize: 1362427 References: 2428 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2429 client_pushes_test.go:97: Retrieved narinfo from S3:2430 StorePath: /build/TestClientPushesUseOnePush3328193807/001/store/hz1gp73aycdb1i2qg5khjmmfz7ckc73b-a2431 URL: nar/1krbi23l8caa1f7agxihz0aw0zvnanqj58cxgag86rhw9hqalhvs.nar.zst2432 Compression: zstd2433 NarHash: sha256:1krbi23l8caa1f7agxihz0aw0zvnanqj58cxgag86rhw9hqalhvs2434 NarSize: 2162435 References: /build/TestClientPushesUseOnePush3328193807/001/store/cdlj3riqbf4smp551nyjmapdaj0jpysr-shared-dep2436 CA: text:sha256:12rlz9r7dpmz457rji3dwxfzlhml9kx31769fwi02l8syjzvxaaj2437=== NAME TestClientWithDependencies2438 client_integration_test.go:615: Found 1 dependencies (including self)2439=== NAME TestClientPushesUseOnePush2440 client_pushes_test.go:97: Retrieved narinfo from S3:2441 StorePath: /build/TestClientPushesUseOnePush3328193807/001/store/rf48pkr0d23a9iav80aqgf4v3hnnhlax-b2442 URL: nar/1krbi23l8caa1f7agxihz0aw0zvnanqj58cxgag86rhw9hqalhvs.nar.zst2443 Compression: zstd2444 NarHash: sha256:1krbi23l8caa1f7agxihz0aw0zvnanqj58cxgag86rhw9hqalhvs2445 NarSize: 2162446 References: /build/TestClientPushesUseOnePush3328193807/001/store/cdlj3riqbf4smp551nyjmapdaj0jpysr-shared-dep2447 CA: text:sha256:12rlz9r7dpmz457rji3dwxfzlhml9kx31769fwi02l8syjzvxaaj2448=== NAME TestClientMultipleUploads2449 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads372420795/001/store/l1925snk69d4wsdd3l9zyf43cgblf21l-test-file-0.txt2450--- PASS: TestClientPushesUseOnePush (0.90s)2451=== NAME TestClientMultipleUploads2452 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads372420795/001/store/ysczbil8k5dv4v3m9m0wvvmfcd9d695d-test-file-1.txt24532026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes24542026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes24552026/09/29 08:15:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24562026/09/29 08:15:49 INFO Uploading 04q36p1azlfj4cnldncpxhzqlvgnlmr6-unpinned-file.txt (128B)24572026/09/29 08:15:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24582026/09/29 08:15:49 INFO Uploading zkn7h1ysv46hdghr1nzcqjbrlzlpddqf-test-file.txt (152B)24592026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"24602026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign24612026/09/29 08:15:49 WARN Failed to register uploaded object key=04q36p1azlfj4cnldncpxhzqlvgnlmr6.ls error="server returned 404: 404 page not found\n"24622026/09/29 08:15:49 INFO Signed narinfos id=2 count=124632026/09/29 08:15:49 INFO Uploading 1 narinfos24642026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"24652026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24662026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/2/complete24672026/09/29 08:15:49 WARN Failed to register uploaded object key=zkn7h1ysv46hdghr1nzcqjbrlzlpddqf.ls error="server returned 404: 404 page not found\n"24682026/09/29 08:15:49 WARN Failed to register uploaded object key=04q36p1azlfj4cnldncpxhzqlvgnlmr6.narinfo error="server returned 404: 404 page not found\n"24692026/09/29 08:15:49 INFO Signed narinfos id=1 count=124702026/09/29 08:15:49 INFO Uploading 1 narinfos24712026/09/29 08:15:49 INFO Upload complete. (48ms)24722026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete24732026/09/29 08:15:49 WARN Failed to register uploaded object key=zkn7h1ysv46hdghr1nzcqjbrlzlpddqf.narinfo error="server returned 404: 404 page not found\n"24742026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes24752026/09/29 08:15:49 INFO Upload complete. (59ms)2476 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads372420795/001/store/m2afwjylb1w7lppg2v2fl26yndbzjx14-test-file-2.txt24772026/09/29 08:15:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24782026/09/29 08:15:49 INFO Uploading g6nc721ga6sk85yjbah2xhhxjifypwzm-test-script (136B)24792026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"24802026/09/29 08:15:49 WARN Failed to register uploaded object key=g6nc721ga6sk85yjbah2xhhxjifypwzm.ls error="server returned 404: 404 page not found\n"24812026/09/29 08:15:49 WARN Failed to register uploaded object key=log/1yap8683sr7pp2zayrj62khygqmq82d8-test-script.drv error="server returned 404: 404 page not found\n"24822026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24832026/09/29 08:15:49 INFO Signed narinfos id=1 count=124842026/09/29 08:15:49 INFO Uploading 1 narinfos24852026/09/29 08:15:49 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24862026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete24872026/09/29 08:15:49 WARN Failed to register uploaded object key=g6nc721ga6sk85yjbah2xhhxjifypwzm.narinfo error="server returned 404: 404 page not found\n"24882026/09/29 08:15:49 INFO Upload complete. (58ms)2489=== NAME TestClientWithDependencies2490 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2218379373/001/store) requires matching store prefix2491--- PASS: TestClientWithDependencies (0.82s)24922026/09/29 08:15:49 INFO Received create pin request method=POST path=/api/pins/myapp24932026/09/29 08:15:49 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3355922326/001/store/d1bj6xmhs3fd74w52hvkhsmsp9mb9dkx-pinned-file.txt narinfo_key=d1bj6xmhs3fd74w52hvkhsmsp9mb9dkx.narinfo24942026/09/29 08:15:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures24952026/09/29 08:15:49 INFO Garbage collection started24962026/09/29 08:15:49 INFO All 1 paths already cached2497=== NAME TestClientIntegration2498 client_integration_test.go:312: Retrieved narinfo from S3:2499 StorePath: /build/TestClientIntegration3832674083/002/store/zkn7h1ysv46hdghr1nzcqjbrlzlpddqf-test-file.txt2500 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2501 Compression: zstd2502 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12503 NarSize: 1522504 References: 2505 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk125062026/09/29 08:15:49 INFO Aborted multipart uploads count=02507 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2508 client_integration_test.go:313: Decompressed .ls content (64 bytes):2509 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2510 client_integration_test.go:316: Testing garbage collection...25112026/09/29 08:15:49 WARN Force mode enabled - objects will be deleted immediately without grace period25122026/09/29 08:15:49 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25132026/09/29 08:15:49 INFO Received push request method=POST path=/api/pushes25142026/09/29 08:15:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures25152026/09/29 08:15:49 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)25162026/09/29 08:15:49 INFO Garbage collection started25172026/09/29 08:15:49 INFO Uploading m2afwjylb1w7lppg2v2fl26yndbzjx14-test-file-2.txt (160B)25182026/09/29 08:15:49 INFO Uploading l1925snk69d4wsdd3l9zyf43cgblf21l-test-file-0.txt (160B)25192026/09/29 08:15:49 INFO Uploading ysczbil8k5dv4v3m9m0wvvmfcd9d695d-test-file-1.txt (160B)25202026/09/29 08:15:49 INFO Aborted multipart uploads count=025212026/09/29 08:15:49 WARN Force mode enabled - objects will be deleted immediately without grace period25222026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"25232026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"25242026/09/29 08:15:49 WARN Failed to register uploaded object key=ysczbil8k5dv4v3m9m0wvvmfcd9d695d.ls error="server returned 404: 404 page not found\n"25252026/09/29 08:15:49 WARN Failed to register uploaded object key=m2afwjylb1w7lppg2v2fl26yndbzjx14.ls error="server returned 404: 404 page not found\n"25262026/09/29 08:15:49 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"25272026/09/29 08:15:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25282026/09/29 08:15:49 WARN Failed to register uploaded object key=l1925snk69d4wsdd3l9zyf43cgblf21l.ls error="server returned 404: 404 page not found\n"25292026/09/29 08:15:49 INFO Signed narinfos id=1 count=325302026/09/29 08:15:49 INFO Uploading 3 narinfos25312026/09/29 08:15:49 WARN Failed to register uploaded object key=l1925snk69d4wsdd3l9zyf43cgblf21l.narinfo error="server returned 404: 404 page not found\n"25322026/09/29 08:15:49 WARN Failed to register uploaded object key=m2afwjylb1w7lppg2v2fl26yndbzjx14.narinfo error="server returned 404: 404 page not found\n"25332026/09/29 08:15:49 INFO Received complete push request method=POST path=/api/pushes/1/complete25342026/09/29 08:15:49 WARN Failed to register uploaded object key=ysczbil8k5dv4v3m9m0wvvmfcd9d695d.narinfo error="server returned 404: 404 page not found\n"25352026/09/29 08:15:49 INFO Upload complete. (86ms)2536=== NAME TestClientMultipleUploads2537 client_integration_test.go:369: Uploaded 3 paths in 120.140657ms2538--- PASS: TestClientMultipleUploads (0.86s)2539--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2540 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2541 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2542 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.79s)25432026/09/29 08:15:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=786.954878ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25442026/09/29 08:15:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.50160686s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25452026/09/29 08:15:50 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=025462026/09/29 08:15:50 INFO Vacuumed table table=pending_closures25472026/09/29 08:15:50 INFO Vacuumed table table=pending_objects25482026/09/29 08:15:50 INFO Vacuumed table table=multipart_uploads25492026/09/29 08:15:50 INFO Vacuumed table table=closures25502026/09/29 08:15:50 INFO Vacuumed table table=objects25512026/09/29 08:15:50 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=025522026/09/29 08:15:50 INFO Vacuumed table table=pending_closures25532026/09/29 08:15:50 INFO Vacuumed table table=pending_objects25542026/09/29 08:15:50 INFO Vacuumed table table=multipart_uploads25552026/09/29 08:15:50 INFO Vacuumed table table=closures25562026/09/29 08:15:50 INFO Vacuumed table table=objects2557=== NAME TestOrphanedObjectsGCStressTest2558 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2559 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2560 orphaned_objects_gc_test.go:509: Stress test completed successfully:2561 orphaned_objects_gc_test.go:510: - Active objects preserved: 202562 orphaned_objects_gc_test.go:511: - Objects deleted: 2102563 orphaned_objects_gc_test.go:512: - Total GC'd: 2102564--- PASS: TestOrphanedObjectsGCStressTest (2.72s)25652026/09/29 08:15:51 WARN Rate limiter enabled after throttle name=s3-test rate=525662026/09/29 08:15:51 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2567=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2568 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102569 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002570--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.16s)25712026/09/29 08:15:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02572=== NAME TestPinProtectsFromGC2573 client_integration_test.go:794: Pin successfully protected closure from garbage collection2574--- PASS: TestPinProtectsFromGC (2.97s)25752026/09/29 08:15:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02576=== NAME TestClientIntegration2577 client_integration_test.go:323: Objects in database after GC:2578 client_integration_test.go:323: Successfully deleted all objects with GC --force2579--- PASS: TestClientIntegration (2.82s)25802026/09/29 08:15:52 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-config25812026/09/29 08:15:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.181463ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/29 08:15:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=406.642097ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25832026/09/29 08:15:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=755.336264ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25842026/09/29 08:15:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.575161198s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25852026/09/29 08:15:55 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"25862026/09/29 08:15:55 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-config25872026/09/29 08:15:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.103205ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25882026/09/29 08:15:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.659767ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25892026/09/29 08:15:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=785.915298ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25902026/09/29 08:15:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.449251614s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25912026/09/29 08:15:58 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_closures25922026/09/29 08:15:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.099906ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25932026/09/29 08:15:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.903793ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25942026/09/29 08:15:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=810.510475ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25952026/09/29 08:15:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.736675644s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2596--- PASS: TestClientErrorHandling (0.00s)2597 --- PASS: TestClientErrorHandling/InvalidStorePath (0.54s)2598 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.62s)2599 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.37s)2600PASS2601{"timestamp":"2026-09-29T08:16:01.454518148Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41118","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(205)"}26022026-09-29 08:16:01.706 UTC [129] LOG: received smart shutdown request26032026-09-29 08:16:01.712 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 126042026-09-29 08:16:01.724 UTC [134] LOG: shutting down26052026-09-29 08:16:01.725 UTC [134] LOG: checkpoint starting: shutdown immediate26062026-09-29 08:16:02.912 UTC [134] LOG: checkpoint complete: wrote 11312 buffers (69.0%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.222 s, sync=0.943 s, total=1.188 s; sync files=21875, longest=0.003 s, average=0.001 s; distance=297523 kB, estimate=297523 kB; lsn=0/139F2AA0, redo lsn=0/139F2AA026072026-09-29 08:16:02.979 UTC [129] LOG: database system is shut down2608Running OIDC tests...2609=== RUN TestAudienceForIssuer2610=== PAUSE TestAudienceForIssuer2611=== RUN TestGlobMatch2612=== PAUSE TestGlobMatch2613=== RUN TestValidateToken_ValidToken2614=== PAUSE TestValidateToken_ValidToken2615=== RUN TestValidateToken_WrongAudience2616=== PAUSE TestValidateToken_WrongAudience2617=== RUN TestValidateToken_Expired2618=== PAUSE TestValidateToken_Expired2619=== RUN TestValidateToken_BoundClaimsMismatch2620=== PAUSE TestValidateToken_BoundClaimsMismatch2621=== RUN TestValidateToken_BoundSubjectMismatch2622=== PAUSE TestValidateToken_BoundSubjectMismatch2623=== RUN TestValidateToken_MultipleProviders2624=== PAUSE TestValidateToken_MultipleProviders2625=== RUN TestValidateToken_NoMatchingProvider2626=== PAUSE TestValidateToken_NoMatchingProvider2627=== RUN TestValidateToken_KubernetesServiceAccount2628=== PAUSE TestValidateToken_KubernetesServiceAccount2629=== RUN TestNewValidator_KubernetesRequiresCA2630=== PAUSE TestNewValidator_KubernetesRequiresCA2631=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2632=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2633=== RUN TestPins_ReservedForMatchingRule2634=== PAUSE TestPins_ReservedForMatchingRule2635=== RUN TestPins_TopLevelShorthand2636=== PAUSE TestPins_TopLevelShorthand2637=== RUN TestPins_ConfigValidation2638=== PAUSE TestPins_ConfigValidation2639=== RUN TestScopes_LegacyProviderDefaultsToWrite2640=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2641=== RUN TestScopes_Rules2642=== PAUSE TestScopes_Rules2643=== RUN TestScopes_ConfigValidation2644=== PAUSE TestScopes_ConfigValidation2645=== CONT TestAudienceForIssuer2646=== CONT TestPins_ConfigValidation2647--- PASS: TestAudienceForIssuer (0.00s)2648=== CONT TestScopes_Rules2649=== CONT TestValidateToken_KubernetesServiceAccount2650=== CONT TestPins_TopLevelShorthand2651=== CONT TestPins_ReservedForMatchingRule2652=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2653--- PASS: TestPins_ConfigValidation (0.00s)2654=== CONT TestNewValidator_KubernetesRequiresCA2655=== CONT TestScopes_LegacyProviderDefaultsToWrite2656=== CONT TestValidateToken_BoundClaimsMismatch2657=== CONT TestValidateToken_NoMatchingProvider2658=== CONT TestValidateToken_MultipleProviders2659=== CONT TestValidateToken_BoundSubjectMismatch2660=== CONT TestScopes_ConfigValidation2661=== CONT TestValidateToken_WrongAudience2662=== CONT TestValidateToken_Expired2663=== CONT TestValidateToken_ValidToken2664=== CONT TestGlobMatch2665--- PASS: TestScopes_ConfigValidation (0.00s)2666=== RUN TestGlobMatch/foo_foo2667=== PAUSE TestGlobMatch/foo_foo2668=== RUN TestGlobMatch/foo_bar2669=== PAUSE TestGlobMatch/foo_bar2670=== RUN TestGlobMatch/*_2671=== PAUSE TestGlobMatch/*_2672=== RUN TestGlobMatch/*_anything2673=== PAUSE TestGlobMatch/*_anything2674=== RUN TestGlobMatch/foo*_foo2675=== PAUSE TestGlobMatch/foo*_foo2676=== RUN TestGlobMatch/foo*_foobar2677=== PAUSE TestGlobMatch/foo*_foobar2678=== RUN TestGlobMatch/foo*_bar2679=== PAUSE TestGlobMatch/foo*_bar2680=== RUN TestGlobMatch/*bar_bar2681=== PAUSE TestGlobMatch/*bar_bar2682=== RUN TestGlobMatch/*bar_foobar2683=== PAUSE TestGlobMatch/*bar_foobar2684=== RUN TestGlobMatch/*bar_foo2685=== PAUSE TestGlobMatch/*bar_foo2686=== RUN TestGlobMatch/foo*bar_foobar2687=== PAUSE TestGlobMatch/foo*bar_foobar2688=== RUN TestGlobMatch/foo*bar_foo123bar2689=== PAUSE TestGlobMatch/foo*bar_foo123bar2690=== RUN TestGlobMatch/foo*bar_foobarbaz2691=== PAUSE TestGlobMatch/foo*bar_foobarbaz2692=== RUN TestGlobMatch/*/*_foo/bar2693=== PAUSE TestGlobMatch/*/*_foo/bar2694=== RUN TestGlobMatch/*/*_foo2695=== PAUSE TestGlobMatch/*/*_foo2696=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2697=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2698=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02699=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02700=== RUN TestGlobMatch/refs/*/main_refs/heads/main2701=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2702=== RUN TestGlobMatch/fo?_foo2703=== PAUSE TestGlobMatch/fo?_foo2704=== RUN TestGlobMatch/fo?_fo2705=== PAUSE TestGlobMatch/fo?_fo2706=== RUN TestGlobMatch/fo?_fooo2707=== PAUSE TestGlobMatch/fo?_fooo2708=== RUN TestGlobMatch/?oo_foo2709=== PAUSE TestGlobMatch/?oo_foo2710=== RUN TestGlobMatch/?oo_boo2711=== PAUSE TestGlobMatch/?oo_boo2712=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2713=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2714=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2715=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2716=== CONT TestGlobMatch/foo_foo2717=== CONT TestGlobMatch/foo*bar_foobarbaz2718=== CONT TestGlobMatch/foo*_foo2719=== CONT TestGlobMatch/*_anything2720=== CONT TestGlobMatch/foo*bar_foo123bar2721=== CONT TestGlobMatch/foo_bar2722=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2723=== CONT TestGlobMatch/?oo_boo2724=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2725=== CONT TestGlobMatch/?oo_foo2726=== CONT TestGlobMatch/*bar_foo2727=== CONT TestGlobMatch/*/*_foo2728=== CONT TestGlobMatch/*/*_foo/bar2729=== CONT TestGlobMatch/fo?_fooo2730=== CONT TestGlobMatch/fo?_fo2731=== CONT TestGlobMatch/*bar_foobar2732=== CONT TestGlobMatch/*bar_bar2733=== CONT TestGlobMatch/foo*_bar2734=== CONT TestGlobMatch/foo*_foobar2735=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2736=== CONT TestGlobMatch/*_2737=== CONT TestGlobMatch/foo*bar_foobar2738=== CONT TestGlobMatch/refs/*/main_refs/heads/main2739=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02740=== CONT TestGlobMatch/fo?_foo2741--- PASS: TestGlobMatch (0.00s)2742 --- PASS: TestGlobMatch/foo_foo (0.00s)2743 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2744 --- PASS: TestGlobMatch/foo*_foo (0.00s)2745 --- PASS: TestGlobMatch/*_anything (0.00s)2746 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2747 --- PASS: TestGlobMatch/foo_bar (0.00s)2748 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2749 --- PASS: TestGlobMatch/?oo_boo (0.00s)2750 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2751 --- PASS: TestGlobMatch/?oo_foo (0.00s)2752 --- PASS: TestGlobMatch/*bar_foo (0.00s)2753 --- PASS: TestGlobMatch/*/*_foo (0.00s)2754 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2755 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2756 --- PASS: TestGlobMatch/fo?_fo (0.00s)2757 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2758 --- PASS: TestGlobMatch/*bar_bar (0.00s)2759 --- PASS: TestGlobMatch/foo*_bar (0.00s)2760 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2761 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2762 --- PASS: TestGlobMatch/*_ (0.00s)2763 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2764 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2765 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2766 --- PASS: TestGlobMatch/fo?_foo (0.00s)27672026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43099/oidc27682026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32919/oidc2769--- PASS: TestValidateToken_WrongAudience (0.03s)2770--- PASS: TestPins_ReservedForMatchingRule (0.04s)27712026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45557/oidc2772--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)27732026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46271/oidc27742026/09/29 08:16:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:445472775--- PASS: TestValidateToken_Expired (0.10s)2776--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)27772026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41919/oidc27782026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33981/oidc27792026/09/29 08:16:04 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232780--- PASS: TestPins_TopLevelShorthand (0.12s)2781--- PASS: TestScopes_Rules (0.13s)2782--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.13s)27832026/09/29 08:16:04 http: TLS handshake error from 127.0.0.1:33826: remote error: tls: bad certificate2784--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)27852026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36713/oidc2786--- PASS: TestValidateToken_BoundSubjectMismatch (0.16s)27872026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40981/oidc27882026/09/29 08:16:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45325/oidc2789--- PASS: TestValidateToken_BoundClaimsMismatch (0.18s)2790--- PASS: TestValidateToken_NoMatchingProvider (0.18s)27912026/09/29 08:16:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35771/oidc2792--- PASS: TestValidateToken_ValidToken (0.25s)27932026/09/29 08:16:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45211/oidc27942026/09/29 08:16:04 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45125/oidc2795--- PASS: TestValidateToken_MultipleProviders (0.30s)2796PASS2797Running hook tests...2798=== RUN TestSendPathsEmpty2799=== PAUSE TestSendPathsEmpty2800=== RUN TestQueueEnqueueAndFetch2801=== PAUSE TestQueueEnqueueAndFetch2802=== RUN TestQueueDeduplication2803=== PAUSE TestQueueDeduplication2804=== RUN TestQueueRemove2805=== PAUSE TestQueueRemove2806=== RUN TestQueueFetchBatchLimit2807=== PAUSE TestQueueFetchBatchLimit2808=== RUN TestQueueRetryMovesToBack2809=== PAUSE TestQueueRetryMovesToBack2810=== RUN TestQueueFetchRemoveLifecycle2811=== PAUSE TestQueueFetchRemoveLifecycle2812=== RUN TestQueueConcurrentWriters2813=== PAUSE TestQueueConcurrentWriters2814=== RUN TestQueueRemoveLargeClosure2815=== PAUSE TestQueueRemoveLargeClosure2816=== RUN TestServerClientIntegration2817=== PAUSE TestServerClientIntegration2818=== RUN TestServerQueueError2819=== PAUSE TestServerQueueError2820=== RUN TestGetListenerSocketActivation2821 server_test.go:210: === RUN TestGetListenerSocketActivation2822 --- PASS: TestGetListenerSocketActivation (0.00s)2823 PASS2824 2825--- PASS: TestGetListenerSocketActivation (0.01s)2826=== RUN TestDrainIsolatesPoisonPath2827=== PAUSE TestDrainIsolatesPoisonPath2828=== RUN TestRunNotBlockedByPoisonHead2829=== PAUSE TestRunNotBlockedByPoisonHead2830=== RUN TestDrainGivesUpWhenServerDown2831=== PAUSE TestDrainGivesUpWhenServerDown2832=== RUN TestFailedPathPrunedByLaterClosure2833=== PAUSE TestFailedPathPrunedByLaterClosure2834=== RUN TestWorkerUploadsAndRemoves2835=== PAUSE TestWorkerUploadsAndRemoves2836=== RUN TestWorkerSkipsGCdPaths2837=== PAUSE TestWorkerSkipsGCdPaths2838=== RUN TestWorkerPrunesClosureDeps2839=== PAUSE TestWorkerPrunesClosureDeps2840=== RUN TestDrainTimeout2841=== PAUSE TestDrainTimeout2842=== CONT TestSendPathsEmpty2843=== CONT TestWorkerSkipsGCdPaths2844=== CONT TestRunNotBlockedByPoisonHead2845=== CONT TestDrainTimeout2846=== CONT TestWorkerUploadsAndRemoves2847=== CONT TestFailedPathPrunedByLaterClosure2848=== CONT TestDrainGivesUpWhenServerDown2849--- PASS: TestSendPathsEmpty (0.00s)2850=== CONT TestQueueFetchRemoveLifecycle2851=== CONT TestQueueRetryMovesToBack2852=== CONT TestDrainIsolatesPoisonPath2853=== CONT TestQueueFetchBatchLimit2854=== CONT TestServerQueueError2855=== CONT TestQueueRemove2856=== CONT TestServerClientIntegration2857=== CONT TestQueueDeduplication2858=== CONT TestQueueRemoveLargeClosure2859=== CONT TestQueueEnqueueAndFetch2860=== CONT TestQueueConcurrentWriters2861=== CONT TestWorkerPrunesClosureDeps28622026/09/29 08:16:04 ERROR Failed to queue paths error="permission denied" count=12863--- PASS: TestServerClientIntegration (0.00s)2864--- PASS: TestServerQueueError (0.00s)28652026/09/29 08:16:04 INFO Upload queue status pending=228662026/09/29 08:16:04 INFO Upload queue status pending=228672026/09/29 08:16:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1882955300/002/nonexistent28682026/09/29 08:16:04 INFO Uploading batch count=128692026/09/29 08:16:04 INFO Uploading batch count=228702026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=228712026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1678056965/002/a28722026/09/29 08:16:04 INFO Uploading batch count=128732026/09/29 08:16:04 INFO Uploading batch count=428742026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=428752026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1678056965/002/b28762026/09/29 08:16:04 INFO Upload queue status pending=328772026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath727244498/002/bbb28782026/09/29 08:16:04 INFO Uploading batch count=128792026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=128802026/09/29 08:16:04 INFO Upload queue status pending=228812026/09/29 08:16:04 INFO Uploading batch count=128822026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=128832026/09/29 08:16:04 INFO Uploading batch count=22884--- PASS: TestQueueDeduplication (0.02s)28852026/09/29 08:16:04 INFO Uploading batch count=228862026/09/29 08:16:04 INFO Uploading batch count=128872026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=128882026/09/29 08:16:04 INFO Uploading batch count=12889--- PASS: TestQueueEnqueueAndFetch (0.02s)28902026/09/29 08:16:04 INFO Uploading batch count=228912026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=228922026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1678056965/002/c28932026/09/29 08:16:04 INFO Uploading batch count=12894--- PASS: TestQueueFetchRemoveLifecycle (0.02s)28952026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=12896--- PASS: TestQueueFetchBatchLimit (0.02s)2897--- PASS: TestQueueRetryMovesToBack (0.02s)28982026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1678056965/002/d28992026/09/29 08:16:04 INFO Uploading batch count=129002026/09/29 08:16:04 INFO Uploading batch count=129012026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=12902--- PASS: TestQueueRemove (0.02s)29032026/09/29 08:16:04 INFO Uploading batch count=229042026/09/29 08:16:04 ERROR Upload failed error="upload failed" count=229052026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1678056965/002/e29062026/09/29 08:16:04 ERROR Drain finished with paths left in queue remaining=129072026/09/29 08:16:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1678056965/002/f29082026/09/29 08:16:04 ERROR Drain finished with paths left in queue remaining=102909--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2910--- PASS: TestDrainIsolatesPoisonPath (0.02s)2911--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2912--- PASS: TestWorkerSkipsGCdPaths (0.04s)2913--- PASS: TestWorkerPrunesClosureDeps (0.04s)2914--- PASS: TestWorkerUploadsAndRemoves (0.04s)2915--- PASS: TestQueueRemoveLargeClosure (0.14s)2916--- PASS: TestQueueConcurrentWriters (0.18s)29172026/09/29 08:16:04 ERROR Upload failed error="context deadline exceeded" count=229182026/09/29 08:16:04 ERROR Drain finished with paths left in queue remaining=42919--- PASS: TestDrainTimeout (0.22s)29202026/09/29 08:16:05 INFO Uploading batch count=129212026/09/29 08:16:05 INFO Uploading batch count=129222026/09/29 08:16:05 INFO Uploading batch count=129232026/09/29 08:16:05 ERROR Upload failed error="upload failed" count=129242026/09/29 08:16:05 INFO Uploading batch count=129252026/09/29 08:16:05 ERROR Upload failed error="upload failed" count=129262026/09/29 08:16:05 INFO Uploading batch count=129272026/09/29 08:16:05 ERROR Upload failed error="upload failed" count=129282026/09/29 08:16:05 INFO Uploading batch count=129292026/09/29 08:16:05 ERROR Upload failed error="upload failed" count=129302026/09/29 08:16:05 ERROR Drain finished with paths left in queue remaining=12931--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2932PASS