niks3-go-unit-tests log

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

1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)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 TestParsePathInfoJSON97=== CONT TestStreamPushGivesUpOnDeadServer98=== RUN TestParsePathInfoJSON/Nix_format99=== PAUSE TestParsePathInfoJSON/Nix_format100=== RUN TestParsePathInfoJSON/Lix_format101=== PAUSE TestParsePathInfoJSON/Lix_format102=== RUN TestParsePathInfoJSON/empty_input103=== PAUSE TestParsePathInfoJSON/empty_input104=== RUN TestParsePathInfoJSON/whitespace_only105=== CONT TestStreamPushReportsSignatures106=== CONT TestScriptTokenEmptyCommand107=== CONT TestScriptTokenScriptFails108=== CONT TestScriptTokenBadJSON1092026/10/01 09:33:42 ERROR Upload failed error="connection refused" count=201102026/10/01 09:33:42 ERROR Server seems unavailable, giving up on batch untried=17111=== CONT TestScriptTokenEmptyToken112=== CONT TestScriptTokenCachesUntilRefresh113=== CONT TestScriptTokenNoExpiryRerunsEveryCall114=== CONT TestFileTokenEmpty115=== CONT TestFileTokenMissing116=== CONT TestShellSplitErrors117=== CONT TestDumpPathSingleFile118=== CONT TestFileTokenReadsAndCaches119=== CONT TestStaticToken120=== CONT TestGetStorePathHash121=== CONT TestSetClientTLSErrors1222026/10/01 09:33:42 ERROR Upload failed error=boom count=1123=== RUN TestGetStorePathHash/valid_store_path124=== CONT TestSetClientTLSDoesNotMutateDefaultTransport125=== CONT TestSetClientTLS126=== CONT TestClientSignaturesByStorePath127=== CONT TestPathInfoCACompatibility128=== CONT TestRateLimiterFeedback129=== CONT TestStreamPushIsolatesFailures130=== CONT TestStreamPushRequestLine131=== CONT TestShellSplit132=== CONT TestStreamPushBatchesUnderLoad133=== PAUSE TestParsePathInfoJSON/whitespace_only134--- PASS: TestScriptTokenEmptyCommand (0.00s)135=== CONT TestStreamPushReportsEveryPath136=== CONT TestPathInfoHashCompatibility137=== CONT TestEncodeNixBase32WithRealHash138=== RUN TestRateLimiterFeedback/429_enables_limiter139=== PAUSE TestGetStorePathHash/valid_store_path140=== RUN TestPathInfoCACompatibility/null_ca_field141=== RUN TestParsePathInfoJSON/invalid_JSON142--- PASS: TestScriptTokenScriptFails (0.00s)143--- PASS: TestShellSplitErrors (0.00s)144--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)145=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1462026/10/01 09:33:42 ERROR Upload failed error="bad path" count=3147=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error148=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error149=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error150=== CONT TestConvertHashToNix32151=== RUN TestConvertHashToNix32/SRI_format_to_Nix32152=== CONT TestCaseHackSuffix153=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32154=== RUN TestSetClientTLSErrors/missing_cert_file155=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error156=== PAUSE TestSetClientTLSErrors/missing_cert_file157=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error1582026/10/01 09:33:42 ERROR Upload failed error=boom count=1159=== RUN TestSetClientTLSErrors/missing_key_file160=== PAUSE TestSetClientTLSErrors/missing_key_file161=== RUN TestSetClientTLSErrors/missing_ca_file162=== RUN TestConvertHashToNix32/already_Nix32_format163=== CONT TestFilterOversizedClosures164=== CONT TestDumpPathWriterError165=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== CONT TestUploadMultipart_PartsInParallel167=== PAUSE TestRateLimiterFeedback/429_enables_limiter168=== PAUSE TestPathInfoCACompatibility/null_ca_field169=== RUN TestPathInfoCACompatibility/old_string_format_-_text170=== PAUSE TestParsePathInfoJSON/invalid_JSON171=== CONT TestDumpPathMatchesNix172=== CONT TestResolveStorePath173=== CONT TestUploadMultipart_SupersededByPeer174=== CONT TestPartSizeForNAR175--- PASS: TestStaticToken (0.00s)176=== CONT TestRegisterUploadedObjectReusesConnections177=== CONT TestEncodeNixBase32178=== RUN TestPartSizeForNAR/zero_stays_at_minimum179=== PAUSE TestSetClientTLSErrors/missing_ca_file180=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181=== PAUSE TestConvertHashToNix32/already_Nix32_format182=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon183=== RUN TestFilterOversizedClosures/no_limit_keeps_everything184=== CONT TestDoWithRetry_BodyReplayedViaGetBody185=== RUN TestRateLimiterFeedback/503_enables_limiter186=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text187=== RUN TestSetClientTLS/rejects_connection_without_client_cert188--- PASS: TestFileTokenMissing (0.00s)189--- PASS: TestStreamPushReportsSignatures (0.00s)190=== CONT TestParsePathInfoJSONMultiplePaths191=== RUN TestUploadMultipart_SupersededByPeer/exists192=== RUN TestSetClientTLSErrors/invalid_ca_file193=== RUN TestEncodeNixBase32/test_string_hash194=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum195=== RUN TestConvertHashToNix32/invalid_format196--- PASS: TestClientSignaturesByStorePath (0.00s)197--- PASS: TestFileTokenEmpty (0.00s)198--- PASS: TestEncodeNixBase32WithRealHash (0.00s)199--- PASS: TestScriptTokenEmptyToken (0.00s)200--- PASS: TestFileTokenReadsAndCaches (0.00s)201--- PASS: TestScriptTokenBadJSON (0.01s)202--- PASS: TestShellSplit (0.00s)203--- PASS: TestStreamPushReportsEveryPath (0.00s)204--- PASS: TestStreamPushIsolatesFailures (0.00s)205--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)206--- PASS: TestDoServerRequestAttachesToken (0.01s)207--- PASS: TestResolveStorePath (0.00s)208=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess209=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths210=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths211=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2122026/10/01 09:33:42 WARN Rate limiter enabled after throttle name=server-test rate=5213=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error215=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error216=== CONT TestGetStorePathHash/basename_without_hyphen_should_error217=== CONT TestParsePathInfoJSON/Nix_format218=== CONT TestParsePathInfoJSON/whitespace_only219=== CONT TestParsePathInfoJSON/invalid_JSON220=== CONT TestParsePathInfoJSON/empty_input221=== CONT TestParsePathInfoJSON/Lix_format222--- PASS: TestParsePathInfoJSON (0.01s)223 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)224 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)225 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)226 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)227 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)228=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything229=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon230=== PAUSE TestRateLimiterFeedback/503_enables_limiter2312026/10/01 09:33:42 WARN Rate limiter enabled after throttle name=server-test rate=5232=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter233=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter234=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter2352026/10/01 09:33:42 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40749236=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter237=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped238=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped239=== RUN TestFilterOversizedClosures/all_closures_skipped240=== PAUSE TestFilterOversizedClosures/all_closures_skipped241=== CONT TestRateLimiterFeedback/429_enables_limiter2422026/10/01 09:33:42 WARN Rate limiter backed off name=server-test rate=5243=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2442026/10/01 09:33:42 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40749245=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2462026/10/01 09:33:42 WARN Rate limiter enabled after throttle name=server-test rate=5247=== PAUSE TestEncodeNixBase32/test_string_hash2482026/10/01 09:33:42 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41737249=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths250=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive251=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2522026/10/01 09:33:42 WARN Rate limiter backed off name=server-test rate=5253=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert254=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA255=== PAUSE TestUploadMultipart_SupersededByPeer/exists256=== PAUSE TestConvertHashToNix32/invalid_format257=== CONT TestFilterOversizedClosures/no_limit_keeps_everything258=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped259=== CONT TestFilterOversizedClosures/all_closures_skipped2602026/10/01 09:33: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=2000261=== CONT TestConvertHashToNix32/SRI_format_to_Nix322622026/10/01 09:33: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=50263=== RUN TestUploadMultipart_SupersededByPeer/missing264=== CONT TestConvertHashToNix32/invalid_format265=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI266=== RUN TestEncodeNixBase32/empty_input267=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter268=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter269--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)271 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)272--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)273=== RUN TestPathInfoCACompatibility/new_structured_format_-_text274=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text275=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method276=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method277=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA278=== CONT TestRateLimiterFeedback/503_enables_limiter279=== RUN TestSetClientTLS/preserves_debug_logging_transport280=== PAUSE TestSetClientTLS/preserves_debug_logging_transport281=== RUN TestPartSizeForNAR/small_stays_at_minimum282=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive283=== CONT TestPathInfoCACompatibility/old_string_format_-_text284=== PAUSE TestPartSizeForNAR/small_stays_at_minimum285=== CONT TestSetClientTLS/rejects_connection_without_client_cert286=== CONT TestGetStorePathHash/valid_store_path287=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA288=== CONT TestConvertHashToNix32/already_Nix32_format289=== PAUSE TestUploadMultipart_SupersededByPeer/missing2902026/10/01 09:33:42 WARN Rate limiter enabled after throttle name=server-test rate=5291=== CONT TestUploadMultipart_SupersededByPeer/exists292=== CONT TestUploadMultipart_SupersededByPeer/missing2932026/10/01 09:33:42 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36515294=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5122952026/10/01 09:33:42 WARN Rate limiter backed off name=server-test rate=5296=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512297=== PAUSE TestEncodeNixBase32/empty_input298--- PASS: TestFilterOversizedClosures (0.03s)299 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)300 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)301 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)302--- PASS: TestGetStorePathHash (0.01s)303 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)304 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)305 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)306 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)307--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)308--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)309--- PASS: TestRateLimiterFeedback (0.03s)310 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)311 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)312 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)313 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)314=== CONT TestPathInfoCACompatibility/new_structured_format_-_text315--- PASS: TestConvertHashToNix32 (0.03s)316 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)317 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)318 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)319=== CONT TestEncodeNixBase32/test_string_hash320=== PAUSE TestSetClientTLSErrors/invalid_ca_file321=== CONT TestSetClientTLSErrors/missing_cert_file322=== CONT TestSetClientTLSErrors/missing_ca_file323=== CONT TestSetClientTLSErrors/invalid_ca_file324=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum325=== CONT TestSetClientTLS/preserves_debug_logging_transport326=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)327=== CONT TestEncodeNixBase32/empty_input328=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512329=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI330=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon331=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method332--- PASS: TestDumpPathSingleFile (0.04s)333=== CONT TestPathInfoCACompatibility/null_ca_field334--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)335 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)336 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)337=== CONT TestSetClientTLSErrors/missing_key_file338=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum339=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts340=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts341--- PASS: TestEncodeNixBase32 (0.03s)342 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)343 --- PASS: TestEncodeNixBase32/empty_input (0.00s)344=== RUN TestPartSizeForNAR/1_TiB345=== PAUSE TestPartSizeForNAR/1_TiB346=== RUN TestPartSizeForNAR/5_TiB_S3_max_object347=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object348=== RUN TestPartSizeForNAR/capped_at_5_GiB349=== PAUSE TestPartSizeForNAR/capped_at_5_GiB350=== CONT TestPartSizeForNAR/zero_stays_at_minimum351--- PASS: TestPathInfoHashCompatibility (0.03s)352 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)353 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)354 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)355 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)356--- PASS: TestPathInfoCACompatibility (0.03s)357 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)358 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)359 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)360 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)361 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)362=== CONT TestPartSizeForNAR/1_TiB363=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum364=== CONT TestPartSizeForNAR/capped_at_5_GiB365=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts366=== CONT TestPartSizeForNAR/small_stays_at_minimum367=== CONT TestPartSizeForNAR/5_TiB_S3_max_object368--- PASS: TestCaseHackSuffix (0.03s)369--- PASS: TestPartSizeForNAR (0.03s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)374 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)375 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)377--- PASS: TestSetClientTLSErrors (0.04s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3822026/10/01 09:33:42 http: TLS handshake error from 127.0.0.1:52712: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.04s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestStreamPushRequestLine (0.05s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.11s)392--- PASS: TestUploadMultipart_PartsInParallel (0.64s)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/postgres3879545808/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/postgres3879545808/data -l logfile start422423/build/postgres3879545808:5432 - no response4242026-10-01 09:33:44.028 UTC [127] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 09:33:44.028 UTC [127] LOG: listening on Unix socket "/build/postgres3879545808/.s.PGSQL.5432"4262026-10-01 09:33:44.033 UTC [134] LOG: database system was shut down at 2026-10-01 09:33:43 UTC4272026-10-01 09:33:44.036 UTC [127] LOG: database system is ready to accept connections428/build/postgres3879545808: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 TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestLeadElectsOneAndHandsOver470=== PAUSE TestLeadElectsOneAndHandsOver471=== RUN TestLeadIncumbentWinsAfterRestart4722026-10-01 09:33:44.416 UTC [563] ERROR: relation "goose_db_version" does not exist at character 364732026-10-01 09:33:44.416 UTC [563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/10/01 09:33:44 OK 20241026095416_initial_model.sql (6.44ms)4752026/10/01 09:33:44 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)4762026/10/01 09:33:44 OK 20251218171726_add_pins.sql (2.4ms)4772026/10/01 09:33:44 OK 20260628120000_add_object_size_and_stats.sql (1.95ms)4782026/10/01 09:33:44 OK 20260905000000_add_claims.sql (2.13ms)4792026/10/01 09:33:44 OK 20260920000000_drop_claims.sql (1.29ms)4802026/10/01 09:33:44 OK 20260923120000_add_pushes.sql (1.31ms)4812026/10/01 09:33:44 goose: successfully migrated database to version: 202609231200004822026/10/01 09:33:44 OK 1_commit_pending_closure.sql (1.57ms)4832026/10/01 09:33:44 OK 2_object_stats_trigger.sql (739.63µs)4842026/10/01 09:33:44 OK 3_commit_push.sql (667.23µs)4852026/10/01 09:33:44 goose: up to current file version: 34862026/10/01 09:33:44 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 09:33:45 INFO lead: released remote=192.0.2.1:12344882026/10/01 09:33:45 INFO lead: acquired remote=192.0.2.1:12344892026/10/01 09:33:45 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestGCAdvisoryLockBlocksConcurrentRun4942026-10-01 09:33:45.183 UTC [572] ERROR: relation "goose_db_version" does not exist at character 364952026-10-01 09:33:45.183 UTC [572] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4962026/10/01 09:33:45 OK 20241026095416_initial_model.sql (7.03ms)4972026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)4982026/10/01 09:33:45 OK 20251218171726_add_pins.sql (2.84ms)4992026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.13ms)5002026/10/01 09:33:45 OK 20260905000000_add_claims.sql (2.46ms)5012026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (1.53ms)5022026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (1.13ms)5032026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200005042026/10/01 09:33:45 OK 1_commit_pending_closure.sql (1.73ms)5052026/10/01 09:33:45 OK 2_object_stats_trigger.sql (808.81µs)5062026/10/01 09:33:45 OK 3_commit_push.sql (739.96µs)5072026/10/01 09:33:45 goose: up to current file version: 3508--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 09:33:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"664--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)665=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== RUN TestProxyWriteTimeout668=== PAUSE TestProxyWriteTimeout669=== RUN TestIsValidUploadKey670=== PAUSE TestIsValidUploadKey671=== RUN TestUploadHandlersRejectInvalidKeys672=== PAUSE TestUploadHandlersRejectInvalidKeys673=== RUN TestUploadHandlersRejectOversizedBody674=== PAUSE TestUploadHandlersRejectOversizedBody675=== RUN TestService_cleanupPendingClosuresHandler676=== PAUSE TestService_cleanupPendingClosuresHandler677=== RUN TestService_createPendingClosureHandler678=== PAUSE TestService_createPendingClosureHandler679=== RUN TestService_verifyS3Integrity680=== PAUSE TestService_verifyS3Integrity681=== RUN TestCompleteMultipartUnregistered682=== PAUSE TestCompleteMultipartUnregistered683=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT684=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT685=== CONT TestService_AuthMiddleware686=== CONT TestReadProxyConditionalGet687=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT688=== CONT TestCompleteMultipartUnregistered689=== CONT TestService_verifyS3Integrity690=== CONT TestService_createPendingClosureHandler691=== CONT TestService_cleanupPendingClosuresHandler692=== CONT TestUploadHandlersRejectOversizedBody693=== CONT TestUploadHandlersRejectInvalidKeys694=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info695=== CONT TestIsValidUploadKey696=== CONT TestProxyWriteTimeout697=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle698=== CONT TestSkippedUploadsHandler699=== CONT TestParseSize700=== CONT TestService_Rustfstest701=== CONT TestPresignedUploadRegisteredBeforeCommit702=== CONT TestCompletedNarNotReofferedAcrossClosures703=== RUN TestProxyWriteTimeout/narinfo704=== PAUSE TestProxyWriteTimeout/narinfo705=== RUN TestProxyWriteTimeout/1_GiB_nar706=== PAUSE TestProxyWriteTimeout/1_GiB_nar707=== RUN TestProxyWriteTimeout/10_GiB_nar708=== CONT TestRedundantMultipartUpload7092026/10/01 09:33:45 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000710=== CONT TestPush_SignsNarinfosOfItsPendingObjects711=== CONT TestPush_RejectsBadRequests712=== CONT TestCommitRacingPendingCleanupKeepsObjects713=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit714=== CONT TestReadProxyHead715=== RUN TestIsValidUploadKey/narinfo716=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info717--- PASS: TestParseSize (0.00s)718=== CONT TestPush_CompleteCommitsEveryRoot719=== CONT TestCompleteMultipartUpload_ErrorButObjectExists720=== PAUSE TestProxyWriteTimeout/10_GiB_nar721=== RUN TestProxyWriteTimeout/unknown_size722=== PAUSE TestProxyWriteTimeout/unknown_size723=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal724=== CONT TestPush_OverlappingRootsStoreOneRowPerKey725=== PAUSE TestIsValidUploadKey/narinfo726=== RUN TestIsValidUploadKey/nar_zst727=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal728=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key729=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key730=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key731=== PAUSE TestIsValidUploadKey/nar_zst732=== RUN TestIsValidUploadKey/nar_xz733=== PAUSE TestIsValidUploadKey/nar_xz734=== RUN TestIsValidUploadKey/nar_plain735=== PAUSE TestIsValidUploadKey/nar_plain736=== RUN TestIsValidUploadKey/listing737=== PAUSE TestIsValidUploadKey/listing738=== RUN TestIsValidUploadKey/build_log739=== PAUSE TestIsValidUploadKey/build_log740=== RUN TestIsValidUploadKey/build_log_home-manager_file741=== PAUSE TestIsValidUploadKey/build_log_home-manager_file742=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key743=== RUN TestIsValidUploadKey/build_log_plus_in_name744=== PAUSE TestIsValidUploadKey/build_log_plus_in_name745=== RUN TestIsValidUploadKey/build_log_question_mark746=== PAUSE TestIsValidUploadKey/build_log_question_mark747=== RUN TestIsValidUploadKey/build_log_equals748=== PAUSE TestIsValidUploadKey/build_log_equals749=== RUN TestIsValidUploadKey/realisation750=== PAUSE TestIsValidUploadKey/realisation751=== RUN TestIsValidUploadKey/realisation_plus_in_output752=== PAUSE TestIsValidUploadKey/realisation_plus_in_output753=== RUN TestIsValidUploadKey/nix-cache-info754=== PAUSE TestIsValidUploadKey/nix-cache-info755=== RUN TestIsValidUploadKey/index.html756=== PAUSE TestIsValidUploadKey/index.html757=== RUN TestIsValidUploadKey/narinfo_key,_nar_type758=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type759=== RUN TestIsValidUploadKey/nar_key,_narinfo_type760=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type761=== RUN TestIsValidUploadKey/listing_key,_narinfo_type762=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type763=== RUN TestIsValidUploadKey/traversal764=== PAUSE TestIsValidUploadKey/traversal765=== RUN TestIsValidUploadKey/traversal_nar766=== PAUSE TestIsValidUploadKey/traversal_nar767=== RUN TestIsValidUploadKey/absolute768=== PAUSE TestIsValidUploadKey/absolute769=== CONT TestReadProxyInvalidPath770=== RUN TestIsValidUploadKey/empty_key771=== PAUSE TestIsValidUploadKey/empty_key772=== RUN TestIsValidUploadKey/unknown_type773=== PAUSE TestIsValidUploadKey/unknown_type774=== CONT TestReadRedirectUsesPublicS3URL775--- PASS: TestSkippedUploadsHandler (0.13s)776=== CONT TestReadProxy4047772026-10-01 09:33:45.648 UTC [638] ERROR: relation "goose_db_version" does not exist at character 367782026-10-01 09:33:45.648 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-10-01 09:33:45.652 UTC [639] ERROR: relation "goose_db_version" does not exist at character 367802026-10-01 09:33:45.652 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026-10-01 09:33:45.659 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367822026-10-01 09:33:45.659 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026-10-01 09:33:45.672 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367842026-10-01 09:33:45.672 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC785=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure786=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure787=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart788=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart789=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts790=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts791=== CONT TestReadProxyRangeRequest7922026-10-01 09:33:45.697 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367932026-10-01 09:33:45.697 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026-10-01 09:33:45.714 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367952026-10-01 09:33:45.714 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026/10/01 09:33:45 OK 20241026095416_initial_model.sql (57.69ms)7972026/10/01 09:33:45 OK 20241026095416_initial_model.sql (45.41ms)7982026/10/01 09:33:45 OK 20241026095416_initial_model.sql (47.75ms)7992026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)8002026-10-01 09:33:45.744 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368012026-10-01 09:33:45.744 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)8032026/10/01 09:33:45 OK 20241026095416_initial_model.sql (19.59ms)8042026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)8052026/10/01 09:33:45 OK 20241026095416_initial_model.sql (45.93ms)8062026/10/01 09:33:45 OK 20251218171726_add_pins.sql (4.99ms)8072026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)8082026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)8092026/10/01 09:33:45 OK 20251218171726_add_pins.sql (4.46ms)8102026/10/01 09:33:45 OK 20251218171726_add_pins.sql (8.52ms)8112026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (6.26ms)8122026/10/01 09:33:45 OK 20251218171726_add_pins.sql (8.45ms)8132026/10/01 09:33:45 OK 20241026095416_initial_model.sql (16.1ms)8142026/10/01 09:33:45 OK 20251218171726_add_pins.sql (6.44ms)8152026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)8162026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.69ms)8172026/10/01 09:33:45 OK 20260905000000_add_claims.sql (6.02ms)8182026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (8.88ms)8192026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (3.55ms)8202026/10/01 09:33:45 OK 20260905000000_add_claims.sql (16.34ms)8212026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (18.8ms)8222026/10/01 09:33:45 OK 20251218171726_add_pins.sql (17.22ms)8232026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (20.68ms)8242026/10/01 09:33:45 OK 20260905000000_add_claims.sql (16.6ms)8252026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (14.29ms)8262026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008272026/10/01 09:33:45 OK 20241026095416_initial_model.sql (28.49ms)8282026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (7.38ms)8292026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (4.16ms)8302026/10/01 09:33:45 OK 1_commit_pending_closure.sql (4.65ms)8312026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)8322026/10/01 09:33:45 OK 20260905000000_add_claims.sql (9.69ms)8332026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (9.89ms)8342026/10/01 09:33:45 OK 20260905000000_add_claims.sql (10.11ms)8352026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (3.72ms)8362026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008372026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (4.08ms)8382026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008392026/10/01 09:33:45 OK 2_object_stats_trigger.sql (3.13ms)8402026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (4.2ms)8412026-10-01 09:33:45.791 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368422026-10-01 09:33:45.791 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8432026/10/01 09:33:45 OK 3_commit_push.sql (3.31ms)8442026/10/01 09:33:45 goose: up to current file version: 38452026/10/01 09:33:45 OK 20251218171726_add_pins.sql (7.03ms)8462026/10/01 09:33:45 OK 20260905000000_add_claims.sql (5.58ms)8472026-10-01 09:33:45.793 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368482026-10-01 09:33:45.793 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8492026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (6.92ms)8502026/10/01 09:33:45 OK 1_commit_pending_closure.sql (5.94ms)8512026/10/01 09:33:45 OK 1_commit_pending_closure.sql (5.45ms)8522026-10-01 09:33:45.795 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368532026-10-01 09:33:45.795 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (4.88ms)8552026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008562026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.68ms)8572026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.57ms)8582026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (4.94ms)8592026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (4.81ms)8602026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008612026/10/01 09:33:45 OK 3_commit_push.sql (2.2ms)8622026/10/01 09:33:45 goose: up to current file version: 38632026/10/01 09:33:45 OK 3_commit_push.sql (2.62ms)8642026/10/01 09:33:45 goose: up to current file version: 38652026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (7.02ms)8662026/10/01 09:33:45 OK 1_commit_pending_closure.sql (4.58ms)8672026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (4.06ms)8682026-10-01 09:33:45.802 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368692026-10-01 09:33:45.802 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008712026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.8ms)8722026/10/01 09:33:45 OK 20260905000000_add_claims.sql (5.17ms)8732026/10/01 09:33:45 OK 1_commit_pending_closure.sql (6.91ms)8742026/10/01 09:33:45 OK 3_commit_push.sql (2.75ms)8752026/10/01 09:33:45 goose: up to current file version: 38762026/10/01 09:33:45 OK 1_commit_pending_closure.sql (4.27ms)8772026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.5ms)8782026-10-01 09:33:45.811 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368792026-10-01 09:33:45.811 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8802026-10-01 09:33:45.812 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368812026-10-01 09:33:45.812 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8822026-10-01 09:33:45.812 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368832026-10-01 09:33:45.812 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8842026/10/01 09:33:45 OK 2_object_stats_trigger.sql (11.01ms)8852026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (13.66ms)8862026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/01 09:33:45 OK 3_commit_push.sql (14.68ms)8902026/10/01 09:33:45 goose: up to current file version: 38912026/10/01 09:33:45 OK 20241026095416_initial_model.sql (17.94ms)8922026/10/01 09:33:45 OK 20241026095416_initial_model.sql (16.38ms)8932026/10/01 09:33:45 OK 3_commit_push.sql (5.89ms)8942026/10/01 09:33:45 goose: up to current file version: 38952026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (5.61ms)8962026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200008972026/10/01 09:33:45 OK 20241026095416_initial_model.sql (15.49ms)8982026-10-01 09:33:45.826 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368992026-10-01 09:33:45.826 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9002026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)9012026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (4.55ms)9022026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (4.36ms)9032026/10/01 09:33:45 OK 1_commit_pending_closure.sql (3.93ms)9042026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.64ms)9052026/10/01 09:33:45 OK 20251218171726_add_pins.sql (4.86ms)9062026/10/01 09:33:45 OK 20251218171726_add_pins.sql (5.09ms)9072026/10/01 09:33:45 OK 3_commit_push.sql (2.13ms)9082026/10/01 09:33:45 goose: up to current file version: 39092026/10/01 09:33:45 OK 20251218171726_add_pins.sql (6.23ms)9102026/10/01 09:33:45 OK 20241026095416_initial_model.sql (12.2ms)9112026-10-01 09:33:45.837 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369122026-10-01 09:33:45.837 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026-10-01 09:33:45.837 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369142026-10-01 09:33:45.837 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.59ms)9162026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.6ms)9172026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.21ms)9182026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)9192026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)9202026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)9212026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.74ms)9222026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)9232026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.83ms)9242026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.75ms)9252026-10-01 09:33:45.842 UTC [662] ERROR: relation "goose_db_version" does not exist at character 369262026-10-01 09:33:45.842 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026-10-01 09:33:45.843 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369282026-10-01 09:33:45.843 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9292026/10/01 09:33:45 OK 20251218171726_add_pins.sql (4.1ms)9302026/10/01 09:33:45 OK 20241026095416_initial_model.sql (12.67ms)9312026-10-01 09:33:45.844 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369322026-10-01 09:33:45.844 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9332026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.79ms)9342026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.88ms)9352026/10/01 09:33:45 OK 20251218171726_add_pins.sql (4.37ms)9362026/10/01 09:33:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9372026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.57ms)9382026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (3.14ms)9392026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)9402026-10-01 09:33:45.846 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369412026-10-01 09:33:45.846 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9422026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.22ms)9432026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200009442026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (3.71ms)9452026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.48ms)9462026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200009472026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)9482026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)9492026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)9502026/10/01 09:33:45 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst951--- PASS: TestCompleteMultipartUnregistered (0.38s)952=== CONT TestReadProxyNarStreaming9532026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.69ms)9542026/10/01 09:33:45 OK 1_commit_pending_closure.sql (3.3ms)9552026/10/01 09:33:45 OK 1_commit_pending_closure.sql (4.16ms)9562026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (3.49ms)9572026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200009582026/10/01 09:33:45 OK 20251218171726_add_pins.sql (5.36ms)9592026/10/01 09:33:45 OK 20260905000000_add_claims.sql (4.4ms)9602026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.3ms)9612026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.98ms)9622026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.27ms)9632026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (3.36ms)9642026/10/01 09:33:45 OK 20260905000000_add_claims.sql (4.41ms)9652026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.58ms)9662026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.7ms)9672026/10/01 09:33:45 OK 3_commit_push.sql (1.85ms)9682026/10/01 09:33:45 goose: up to current file version: 39692026/10/01 09:33:45 OK 3_commit_push.sql (2.06ms)9702026/10/01 09:33:45 goose: up to current file version: 39712026/10/01 09:33:45 OK 20241026095416_initial_model.sql (10.44ms)9722026-10-01 09:33:45.857 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369732026-10-01 09:33:45.857 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9742026/10/01 09:33:45 OK 1_commit_pending_closure.sql (5.37ms)9752026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.96ms)9762026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (3.64ms)9772026-10-01 09:33:45.858 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369782026-10-01 09:33:45.858 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9792026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.94ms)9802026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200009812026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.86ms)9822026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200009832026/10/01 09:33:45 OK 20251218171726_add_pins.sql (4.28ms)9842026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (6.45ms)9852026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)9862026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.11ms)9872026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)9882026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.62ms)9892026/10/01 09:33:45 goose: successfully migrated database to version: 202609231200009902026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.09ms)9912026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.98ms)9922026/10/01 09:33:45 OK 3_commit_push.sql (2.13ms)9932026/10/01 09:33:45 goose: up to current file version: 39942026/10/01 09:33:45 OK 1_commit_pending_closure.sql (3.15ms)9952026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.36ms)9962026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.28ms)9972026/10/01 09:33:45 OK 20241026095416_initial_model.sql (11.38ms)9982026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.4ms)9992026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)10002026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)10012026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.33ms)10022026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.61ms)10032026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.23ms)10042026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.44ms)10052026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)10062026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)10072026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.2ms)10082026/10/01 09:33:45 OK 3_commit_push.sql (1.39ms)10092026/10/01 09:33:45 goose: up to current file version: 310102026/10/01 09:33:45 OK 3_commit_push.sql (1.54ms)10112026/10/01 09:33:45 goose: up to current file version: 310122026/10/01 09:33:45 OK 20241026095416_initial_model.sql (10.79ms)10132026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.46ms)10142026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.22ms)10152026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)10162026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.96ms)10172026/10/01 09:33:45 OK 3_commit_push.sql (1.77ms)10182026/10/01 09:33:45 goose: up to current file version: 310192026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (3.01ms)10202026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010212026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)10222026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.58ms)10232026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)10242026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.55ms)10252026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures10262026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.24ms)10272026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)10282026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.61ms)10292026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.2ms)10302026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010312026/10/01 09:33:45 OK 1_commit_pending_closure.sql (3.92ms)10322026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.87ms)10332026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.68ms)10342026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)10352026/10/01 09:33:45 OK 20260905000000_add_claims.sql (2.59ms)10362026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)10372026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.36ms)10382026/10/01 09:33:45 OK 20241026095416_initial_model.sql (9.9ms)10392026/10/01 09:33:45 OK 20241026095416_initial_model.sql (10.35ms)10402026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.9ms)10412026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.88ms)10422026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (3.42ms)10432026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (3.11ms)10442026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (3.02ms)10452026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010462026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.58ms)10472026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)10482026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)10492026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.5ms)10502026/10/01 09:33:45 OK 3_commit_push.sql (2.52ms)10512026/10/01 09:33:45 OK 20260905000000_add_claims.sql (5.2ms)10522026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.41ms)10532026/10/01 09:33:45 goose: up to current file version: 310542026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.33ms)10552026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010562026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.39ms)10572026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010582026/10/01 09:33:45 OK 3_commit_push.sql (779.62µs)10592026/10/01 09:33:45 goose: up to current file version: 310602026/10/01 09:33:45 OK 1_commit_pending_closure.sql (1.75ms)10612026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (1.98ms)10622026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.3ms)10632026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.21ms)10642026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.68ms)10652026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.96ms)10662026/10/01 09:33:45 OK 20251218171726_add_pins.sql (3.76ms)10672026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.43ms)10682026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010692026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.5ms)10702026/10/01 09:33:45 OK 1_commit_pending_closure.sql (3.11ms)10712026/10/01 09:33:45 OK 3_commit_push.sql (1.65ms)10722026/10/01 09:33:45 goose: up to current file version: 310732026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.76ms)10742026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.22ms)10752026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010762026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.84ms)10772026-10-01 09:33:45.884 UTC [670] ERROR: relation "goose_db_version" does not exist at character 3610782026-10-01 09:33:45.884 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10792026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.58ms)10802026/10/01 09:33:45 OK 1_commit_pending_closure.sql (3.11ms)10812026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)10822026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)10832026/10/01 09:33:45 OK 3_commit_push.sql (2.03ms)10842026/10/01 09:33:45 goose: up to current file version: 310852026/10/01 09:33:45 OK 3_commit_push.sql (1.65ms)10862026/10/01 09:33:45 goose: up to current file version: 310872026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.42ms)1088--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.41s)1089=== CONT TestReadRedirectKeepsNarinfoProxied10902026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.46ms)10912026/10/01 09:33:45 OK 2_object_stats_trigger.sql (2.12ms)10922026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.52ms)10932026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000010942026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.09ms)10952026/10/01 09:33:45 OK 3_commit_push.sql (1.79ms)10962026/10/01 09:33:45 goose: up to current file version: 310972026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.63ms)10982026/10/01 09:33:45 OK 3_commit_push.sql (1.59ms)10992026/10/01 09:33:45 goose: up to current file version: 311002026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.02ms)11012026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (1.88ms)11022026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.27ms)11032026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.87ms)11042026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (1.89ms)11052026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000011062026/10/01 09:33:45 OK 3_commit_push.sql (1.32ms)11072026/10/01 09:33:45 goose: up to current file version: 311082026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.43ms)11092026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000011102026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.4ms)11112026/10/01 09:33:45 OK 1_commit_pending_closure.sql (1.38ms)11122026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.55ms)11132026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.45ms)11142026/10/01 09:33:45 OK 3_commit_push.sql (1.54ms)11152026/10/01 09:33:45 goose: up to current file version: 311162026/10/01 09:33:45 INFO Received cleanup request method=DELETE path=/api/pending_closures11172026/10/01 09:33:45 OK 3_commit_push.sql (1.69ms)11182026/10/01 09:33:45 goose: up to current file version: 311192026/10/01 09:33:45 OK 20241026095416_initial_model.sql (8.75ms)11202026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)11212026/10/01 09:33:45 OK 20251218171726_add_pins.sql (2.87ms)11222026/10/01 09:33:45 INFO Aborted multipart uploads count=011232026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)11242026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures11252026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.12ms)11262026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.88ms)11272026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (2.33ms)11282026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000011292026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.32ms)11302026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.28ms)11312026/10/01 09:33:45 INFO Received cleanup request method=DELETE path=/api/pending_closures11322026/10/01 09:33:45 OK 3_commit_push.sql (1.18ms)11332026/10/01 09:33:45 goose: up to current file version: 311342026/10/01 09:33:45 INFO Aborted multipart uploads count=111352026/10/01 09:33:45 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1136--- PASS: TestService_AuthMiddleware (0.45s)1137=== CONT TestReadProxyNarinfoAlreadyDecompressed11382026/10/01 09:33:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11392026-10-01 09:33:45.939 UTC [641] ERROR: Closure does not exist: id=111402026-10-01 09:33:45.939 UTC [641] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11412026-10-01 09:33:45.939 UTC [641] STATEMENT: -- name: CommitPendingClosure :exec1142 SELECT commit_pending_closure($1::bigint)1143 1144--- PASS: TestService_cleanupPendingClosuresHandler (0.47s)1145=== CONT TestReadProxyNarinfo11462026-10-01 09:33:45.949 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3611472026-10-01 09:33:45.949 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures11492026/10/01 09:33:45 OK 20241026095416_initial_model.sql (9.66ms)11502026/10/01 09:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)11512026/10/01 09:33:45 OK 20251218171726_add_pins.sql (2.94ms)11522026/10/01 09:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)11532026/10/01 09:33:45 OK 20260905000000_add_claims.sql (3.22ms)11542026/10/01 09:33:45 OK 20260920000000_drop_claims.sql (2.05ms)11552026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures11562026/10/01 09:33:45 OK 20260923120000_add_pushes.sql (1.97ms)11572026/10/01 09:33:45 goose: successfully migrated database to version: 2026092312000011582026/10/01 09:33:45 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11592026/10/01 09:33:45 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/01 09:33:45 OK 1_commit_pending_closure.sql (2.27ms)11612026/10/01 09:33:45 OK 2_object_stats_trigger.sql (1.5ms)1162--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.51s)1163=== CONT TestIsValidCachePath1164=== RUN TestIsValidCachePath/narinfo1165=== PAUSE TestIsValidCachePath/narinfo1166=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1167=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1168=== RUN TestIsValidCachePath/nar_zst1169=== PAUSE TestIsValidCachePath/nar_zst1170=== RUN TestIsValidCachePath/nar_xz1171=== PAUSE TestIsValidCachePath/nar_xz1172=== RUN TestIsValidCachePath/nar_bz21173=== PAUSE TestIsValidCachePath/nar_bz211742026/10/01 09:33:45 OK 3_commit_push.sql (1.76ms)1175=== RUN TestIsValidCachePath/nar_uncompressed11762026/10/01 09:33:45 goose: up to current file version: 31177=== PAUSE TestIsValidCachePath/nar_uncompressed1178=== RUN TestIsValidCachePath/ls1179=== PAUSE TestIsValidCachePath/ls1180=== RUN TestIsValidCachePath/log1181=== PAUSE TestIsValidCachePath/log1182=== RUN TestIsValidCachePath/realisation1183=== PAUSE TestIsValidCachePath/realisation1184=== RUN TestIsValidCachePath/nix-cache-info1185=== PAUSE TestIsValidCachePath/nix-cache-info1186=== RUN TestIsValidCachePath/index.html1187=== PAUSE TestIsValidCachePath/index.html1188=== RUN TestIsValidCachePath/traversal_parent1189=== PAUSE TestIsValidCachePath/traversal_parent1190=== RUN TestIsValidCachePath/traversal_in_middle1191=== PAUSE TestIsValidCachePath/traversal_in_middle1192=== RUN TestIsValidCachePath/invalid_char_e1193=== PAUSE TestIsValidCachePath/invalid_char_e1194=== RUN TestIsValidCachePath/invalid_char_u1195=== PAUSE TestIsValidCachePath/invalid_char_u1196=== RUN TestIsValidCachePath/random_path1197=== PAUSE TestIsValidCachePath/random_path1198=== RUN TestIsValidCachePath/empty1199=== PAUSE TestIsValidCachePath/empty1200=== RUN TestIsValidCachePath/leading_slash1201=== PAUSE TestIsValidCachePath/leading_slash1202=== RUN TestIsValidCachePath/wrong_extension1203=== PAUSE TestIsValidCachePath/wrong_extension1204=== RUN TestIsValidCachePath/short_hash1205=== PAUSE TestIsValidCachePath/short_hash1206=== CONT TestReadRedirectNar12072026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures12082026-10-01 09:33:46.025 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3612092026-10-01 09:33:46.025 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12102026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures12112026-10-01 09:33:46.029 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3612122026-10-01 09:33:46.029 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12132026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures12142026-10-01 09:33:46.038 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3612152026-10-01 09:33:46.038 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12162026/10/01 09:33:46 OK 20241026095416_initial_model.sql (7.73ms)12172026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)12182026/10/01 09:33:46 OK 20241026095416_initial_model.sql (7.11ms)12192026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)12202026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.34ms)12212026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.38ms)12222026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)12232026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)12242026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.36ms)12252026/10/01 09:33:46 OK 20260905000000_add_claims.sql (10.22ms)12262026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (10.34ms)12272026/10/01 09:33:46 OK 20241026095416_initial_model.sql (17ms)12282026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.81ms)12292026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)12302026/10/01 09:33:46 INFO Received push request method=POST path=/api/pushes12312026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.49ms)12322026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000012332026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.65ms)12342026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000012352026/10/01 09:33:46 OK 1_commit_pending_closure.sql (1.91ms)12362026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.24ms)12372026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.43ms)12382026/10/01 09:33:46 OK 2_object_stats_trigger.sql (971.2µs)12392026/10/01 09:33:46 OK 2_object_stats_trigger.sql (927.61µs)12402026/10/01 09:33:46 OK 3_commit_push.sql (657.75µs)12412026/10/01 09:33:46 goose: up to current file version: 312422026/10/01 09:33:46 OK 3_commit_push.sql (953.98µs)12432026/10/01 09:33:46 goose: up to current file version: 312442026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.03ms)12452026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.67ms)12462026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.54ms)12472026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.28ms)12482026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000012492026/10/01 09:33:46 OK 1_commit_pending_closure.sql (1.64ms)12502026/10/01 09:33:46 OK 2_object_stats_trigger.sql (719.92µs)12512026/10/01 09:33:46 OK 3_commit_push.sql (1.54ms)12522026/10/01 09:33:46 goose: up to current file version: 312532026-10-01 09:33:46.082 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3612542026-10-01 09:33:46.082 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12552026/10/01 09:33:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12562026/10/01 09:33:46 INFO Signed narinfos id=1 count=11257--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.61s)1258=== CONT TestProxyHeadersOnlyTrustedOnSocket12592026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures12602026/10/01 09:33:46 OK 20241026095416_initial_model.sql (7.33ms)12612026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (954µs)12622026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.6ms)12632026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (2.89ms)12642026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.91ms)12652026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.49ms)12662026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.8ms)12672026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000012682026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.37ms)12692026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.56ms)12702026/10/01 09:33:46 OK 3_commit_push.sql (1.92ms)12712026/10/01 09:33:46 goose: up to current file version: 312722026/10/01 09:33:46 INFO Received push request method=POST path=/api/pushes1273--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.67s)1274=== CONT TestReadProxyDisabled1275--- PASS: TestService_Rustfstest (0.68s)1276=== CONT TestParseSingleRange1277=== RUN TestParseSingleRange/none1278=== PAUSE TestParseSingleRange/none1279=== RUN TestParseSingleRange/unknown_unit1280=== PAUSE TestParseSingleRange/unknown_unit1281=== RUN TestParseSingleRange/multi-range_ignored1282=== PAUSE TestParseSingleRange/multi-range_ignored1283=== RUN TestParseSingleRange/malformed_no_dash1284=== PAUSE TestParseSingleRange/malformed_no_dash1285=== RUN TestParseSingleRange/malformed_both_empty1286=== PAUSE TestParseSingleRange/malformed_both_empty1287=== RUN TestParseSingleRange/malformed_end_before_start1288=== PAUSE TestParseSingleRange/malformed_end_before_start1289=== RUN TestParseSingleRange/closed1290=== PAUSE TestParseSingleRange/closed1291=== RUN TestParseSingleRange/open-ended1292=== PAUSE TestParseSingleRange/open-ended1293=== RUN TestParseSingleRange/end_clamped_to_size1294=== PAUSE TestParseSingleRange/end_clamped_to_size1295=== RUN TestParseSingleRange/suffix1296=== PAUSE TestParseSingleRange/suffix1297=== RUN TestParseSingleRange/suffix_exceeds_size1298=== PAUSE TestParseSingleRange/suffix_exceeds_size1299=== RUN TestParseSingleRange/single_byte1300=== PAUSE TestParseSingleRange/single_byte1301=== RUN TestParseSingleRange/start_past_EOF1302=== PAUSE TestParseSingleRange/start_past_EOF1303=== RUN TestParseSingleRange/start_far_past_EOF1304=== PAUSE TestParseSingleRange/start_far_past_EOF1305=== CONT TestReadProxyRootRedirectsToIndexHTML13062026-10-01 09:33:46.172 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3613072026-10-01 09:33:46.172 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13082026/10/01 09:33:46 OK 20241026095416_initial_model.sql (8.91ms)13092026/10/01 09:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13102026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)1311--- PASS: TestReadProxyConditionalGet (0.72s)1312=== CONT TestPresentNotReportedWhileGCDeletesClosure13132026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.5ms)13142026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)13152026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.95ms)13162026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.61ms)13172026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (3.21ms)13182026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000013192026/10/01 09:33:46 INFO Received push request method=POST path=/api/pushes13202026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.12ms)13212026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.53ms)13222026/10/01 09:33:46 OK 3_commit_push.sql (1.55ms)13232026/10/01 09:33:46 goose: up to current file version: 313242026/10/01 09:33:46 INFO Received push request method=POST path=/api/pushes13252026-10-01 09:33:46.241 UTC [698] ERROR: relation "goose_db_version" does not exist at character 3613262026-10-01 09:33:46.241 UTC [698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/10/01 09:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13282026/10/01 09:33:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13292026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.01ms)1330--- PASS: TestPush_CompleteCommitsEveryRoot (0.78s)1331=== CONT TestPresentReportsOnlyClosureRoots13322026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)13332026-10-01 09:33:46.260 UTC [699] ERROR: relation "goose_db_version" does not exist at character 3613342026-10-01 09:33:46.260 UTC [699] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13352026/10/01 09:33:46 OK 20251218171726_add_pins.sql (6.3ms)13362026/10/01 09:33:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (2.8ms)13382026/10/01 09:33:46 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTk2YmY4ZDktZTg3OC00NmQ5LTgzMmItNTI2ZDAyMWE2YTMxLjJjOWM5ODlkLTY3YmEtNGM1MS04NGUwLTdjYTZiMDA0YWE0NHgxNzkwODQ3MjI1ODM3NTc2NTI1 parts=1013392026/10/01 09:33:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13402026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.67ms)13412026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.28ms)1342--- PASS: TestReadProxyInvalidPath (0.67s)1343=== CONT TestGenerateLandingPage13442026/10/01 09:33:46 INFO Completed upload id=113452026/10/01 09:33:46 INFO Received push request method=POST path=/api/pushes13462026/10/01 09:33:46 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013472026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.81ms)13482026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000013492026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures1350--- PASS: TestGenerateLandingPage (0.00s)1351=== CONT TestCreatePin_ReservedPins13522026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.21ms)13532026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.94ms)13542026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)13552026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.17ms)13562026/10/01 09:33:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures13572026/10/01 09:33:46 OK 3_commit_push.sql (1.11ms)13582026/10/01 09:33:46 goose: up to current file version: 313592026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.14ms)13602026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)13612026-10-01 09:33:46.290 UTC [721] ERROR: relation "goose_db_version" does not exist at character 3613622026-10-01 09:33:46.290 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.67ms)13642026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.36ms)13652026/10/01 09:33:46 INFO Aborted multipart uploads count=013662026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.9ms)13672026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000013682026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.92ms)13692026/10/01 09:33:46 OK 2_object_stats_trigger.sql (993.72µs)13702026/10/01 09:33:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013712026/10/01 09:33:46 OK 3_commit_push.sql (1.26ms)13722026/10/01 09:33:46 goose: up to current file version: 313732026/10/01 09:33:46 OK 20241026095416_initial_model.sql (7.74ms)13742026/10/01 09:33:46 INFO Vacuumed table table=pending_closures13752026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)13762026/10/01 09:33:46 INFO Vacuumed table table=pending_objects13772026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.4ms)13782026/10/01 09:33:46 INFO Vacuumed table table=multipart_uploads13792026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)13802026/10/01 09:33:46 INFO Vacuumed table table=closures13812026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.98ms)13822026/10/01 09:33:46 INFO Vacuumed table table=objects13832026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (1.91ms)1384--- PASS: TestReadProxyHead (0.74s)1385=== CONT TestService_readinessHandler13862026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.88ms)13872026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000013882026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.4ms)13892026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.44ms)13902026/10/01 09:33:46 OK 3_commit_push.sql (1.34ms)13912026/10/01 09:33:46 goose: up to current file version: 313922026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures13932026/10/01 09:33:46 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001394--- PASS: TestService_createPendingClosureHandler (0.86s)1395=== CONT TestOrphanedObjectsGCStressTest13962026-10-01 09:33:46.338 UTC [725] ERROR: relation "goose_db_version" does not exist at character 3613972026-10-01 09:33:46.338 UTC [725] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13982026/10/01 09:33:46 INFO Aborted multipart uploads count=013992026/10/01 09:33:46 WARN Force mode enabled - objects will be deleted immediately without grace period14002026/10/01 09:33:46 OK 20241026095416_initial_model.sql (8.44ms)14012026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)14022026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.56ms)14032026/10/01 09:33:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=014042026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)14052026/10/01 09:33:46 INFO Vacuumed table table=pending_closures14062026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.19ms)14072026/10/01 09:33:46 INFO Vacuumed table table=pending_objects14082026/10/01 09:33:46 INFO Vacuumed table table=multipart_uploads14092026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.36ms)14102026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.7ms)14112026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000014122026/10/01 09:33:46 INFO Vacuumed table table=closures14132026/10/01 09:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14142026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.17ms)14152026/10/01 09:33:46 INFO Vacuumed table table=objects14162026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.34ms)14172026/10/01 09:33:46 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTk2YmY4ZDktZTg3OC00NmQ5LTgzMmItNTI2ZDAyMWE2YTMxLjhjZmVmNmE1LWRhN2EtNDUwOC04NWUwLTc1ZmMxZDZkODc3ZngxNzkwODQ3MjI2MzQ1MjcwNDY414182026/10/01 09:33:46 INFO Received complete push request method=POST path=/api/pushes/2/complete14192026/10/01 09:33:46 OK 3_commit_push.sql (1.23ms)14202026/10/01 09:33:46 goose: up to current file version: 31421--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.81s)1422=== CONT TestOrphanedObjectsGC14232026/10/01 09:33:46 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTk2YmY4ZDktZTg3OC00NmQ5LTgzMmItNTI2ZDAyMWE2YTMxLjhjZmVmNmE1LWRhN2EtNDUwOC04NWUwLTc1ZmMxZDZkODc3ZngxNzkwODQ3MjI2MzQ1MjcwNDY4 parts=11424--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.79s)1425=== CONT TestService_healthCheckHandler14262026-10-01 09:33:46.406 UTC [734] ERROR: relation "goose_db_version" does not exist at character 3614272026-10-01 09:33:46.406 UTC [734] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14282026/10/01 09:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14292026/10/01 09:33:46 INFO Aborted multipart uploads count=01430--- PASS: TestReadRedirectUsesPublicS3URL (0.81s)1431=== CONT TestObjectStatsTrigger14322026/10/01 09:33:46 WARN Force mode enabled - objects will be deleted immediately without grace period14332026/10/01 09:33:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014342026/10/01 09:33:46 INFO Vacuumed table table=pending_closures1435--- PASS: TestReadProxy404 (0.82s)1436=== CONT TestGracefulShutdownDrainsInflight14372026/10/01 09:33:46 INFO Starting HTTP server address=127.0.0.1:3652514382026/10/01 09:33:46 INFO Shutdown signal received, draining in-flight requests timeout=10s14392026/10/01 09:33:46 INFO Vacuumed table table=pending_objects14402026/10/01 09:33:46 INFO Vacuumed table table=multipart_uploads14412026/10/01 09:33:46 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTk2YmY4ZDktZTg3OC00NmQ5LTgzMmItNTI2ZDAyMWE2YTMxLjM4YzUwNDllLWIxYWEtNDY1OC04MmQ0LWU5YTE4NjQxZmJjY3gxNzkwODQ3MjI1OTkzODAwNzI5 parts=1014422026/10/01 09:33:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14432026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.51ms)14442026/10/01 09:33:46 INFO Vacuumed table table=closures14452026/10/01 09:33:46 INFO Vacuumed table table=objects14462026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)14472026-10-01 09:33:46.435 UTC [738] ERROR: relation "goose_db_version" does not exist at character 3614482026-10-01 09:33:46.435 UTC [738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14492026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.01ms)14502026/10/01 09:33:46 INFO Completed upload id=114512026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures14522026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)1453--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.84s)1454=== CONT TestGCTaskStore_Fail1455--- PASS: TestGCTaskStore_Fail (0.00s)1456=== CONT TestMultipartCleanup14572026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures14582026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.41ms)14592026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.87ms)14602026/10/01 09:33:46 OK 20241026095416_initial_model.sql (8.47ms)14612026/10/01 09:33:46 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14622026/10/01 09:33:46 WARN Found objects in DB but missing from S3, will re-upload count=114632026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.2ms)14642026/10/01 09:33:46 goose: successfully migrated database to version: 202609231200001465--- PASS: TestService_verifyS3Integrity (0.98s)1466=== CONT TestGCTaskStore_PhaseUpdates1467--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1468=== CONT TestGCTaskStore_CompletedAllowsNewTask1469--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1470=== CONT TestServerTLSConfig1471=== RUN TestServerTLSConfig/no_client_CA1472=== PAUSE TestServerTLSConfig/no_client_CA1473=== RUN TestServerTLSConfig/missing_CA_file1474=== PAUSE TestServerTLSConfig/missing_CA_file1475=== RUN TestServerTLSConfig/not_a_PEM_file1476=== PAUSE TestServerTLSConfig/not_a_PEM_file1477=== CONT TestGCTaskStore_GetReturnsLatest14782026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)1479--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1480=== CONT TestService_NativeMTLS14812026/10/01 09:33:46 OK 1_commit_pending_closure.sql (3.2ms)14822026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.17ms)14832026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.02ms)1484=== RUN TestPush_RejectsBadRequests/no_objects1485=== PAUSE TestPush_RejectsBadRequests/no_objects1486=== RUN TestPush_RejectsBadRequests/bad_root1487=== PAUSE TestPush_RejectsBadRequests/bad_root1488=== RUN TestPush_RejectsBadRequests/root_not_in_objects1489=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1490=== RUN TestPush_RejectsBadRequests/no_roots14912026/10/01 09:33:46 OK 3_commit_push.sql (1.89ms)1492=== PAUSE TestPush_RejectsBadRequests/no_roots14932026/10/01 09:33:46 goose: up to current file version: 31494=== CONT TestGCTaskStore_GetEmpty1495--- PASS: TestGCTaskStore_GetEmpty (0.00s)1496=== CONT TestMetricsInventory14972026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)14982026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.95ms)14992026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.03ms)15002026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.51ms)15012026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000015022026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.33ms)15032026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.23ms)15042026/10/01 09:33:46 OK 3_commit_push.sql (1.64ms)15052026/10/01 09:33:46 goose: up to current file version: 315062026-10-01 09:33:46.484 UTC [745] ERROR: relation "goose_db_version" does not exist at character 3615072026-10-01 09:33:46.484 UTC [745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1508--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1509=== CONT TestGCTaskStore_ConflictDifferentParams1510--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1511=== CONT TestNARDeduplicationMetadataUploadBug1512--- PASS: TestReadProxyRangeRequest (0.83s)1513=== CONT TestGCTaskStore_DeduplicateSameParams1514--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1515=== CONT TestCreatePendingClosureRejectsOversizedNAR15162026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures1517--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1518=== CONT TestGCTaskStore_StartNew1519--- PASS: TestGCTaskStore_StartNew (0.00s)1520=== CONT TestCacheConfigHandlerMaxNarSize1521--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1522=== CONT TestGCEndsOnShutdown15232026-10-01 09:33:46.510 UTC [748] ERROR: relation "goose_db_version" does not exist at character 3615242026-10-01 09:33:46.510 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15252026/10/01 09:33:46 OK 20241026095416_initial_model.sql (11.02ms)15262026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)15272026-10-01 09:33:46.518 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3615282026-10-01 09:33:46.518 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15292026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.16ms)15302026/10/01 09:33:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37357/oidc15312026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)15322026/10/01 09:33:46 OK 20241026095416_initial_model.sql (10.95ms)15332026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.61ms)15342026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)1535--- PASS: TestReadProxyNarStreaming (0.68s)1536=== CONT TestResolveDBConnectionString1537=== RUN TestResolveDBConnectionString/flag_wins1538=== PAUSE TestResolveDBConnectionString/flag_wins1539=== RUN TestResolveDBConnectionString/file_when_flag_empty1540=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1541=== RUN TestResolveDBConnectionString/missing_file_is_an_error1542=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1543=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1544=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1545=== RUN TestResolveDBConnectionString/nothing_configured1546=== PAUSE TestResolveDBConnectionString/nothing_configured1547=== CONT TestTombstonedObjectOfferedWithoutWaiting15482026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.97ms)15492026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.48ms)15502026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.82ms)15512026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)15522026/10/01 09:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15532026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.85ms)15542026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000015552026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.5ms)15562026/10/01 09:33:46 OK 1_commit_pending_closure.sql (3.87ms)15572026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (5ms)15582026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.55ms)15592026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)15602026/10/01 09:33:46 OK 3_commit_push.sql (1.85ms)15612026/10/01 09:33:46 goose: up to current file version: 315622026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.7ms)15632026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.74ms)15642026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.65ms)15652026-10-01 09:33:46.550 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3615662026-10-01 09:33:46.550 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15672026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.75ms)15682026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000015692026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (4.01ms)15702026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.39ms)15712026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.31ms)15722026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000015732026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.79ms)1574--- PASS: TestReadRedirectKeepsNarinfoProxied (0.68s)1575=== CONT TestGCSweepDeliversEachKeyOnce15762026/10/01 09:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15772026/10/01 09:33:46 OK 3_commit_push.sql (17.4ms)15782026/10/01 09:33:46 goose: up to current file version: 315792026/10/01 09:33:46 OK 20241026095416_initial_model.sql (17.35ms)15802026/10/01 09:33:46 OK 1_commit_pending_closure.sql (19.1ms)15812026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.57ms)15822026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)15832026/10/01 09:33:46 OK 3_commit_push.sql (2.28ms)15842026/10/01 09:33:46 goose: up to current file version: 315852026/10/01 09:33:46 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTk2YmY4ZDktZTg3OC00NmQ5LTgzMmItNTI2ZDAyMWE2YTMxLmRkOWIyZGMwLWQ1ZWEtNGJhYy1iMjNmLWFiZTliMWIwMzA3OXgxNzkwODQ3MjI2MDIyNTkwNzM1 parts=121586--- PASS: TestRedundantMultipartUpload (1.10s)1587=== CONT TestGCSweepSkipsPendingObjects15882026/10/01 09:33:46 OK 20251218171726_add_pins.sql (4.41ms)15892026-10-01 09:33:46.584 UTC [759] ERROR: relation "goose_db_version" does not exist at character 3615902026-10-01 09:33:46.584 UTC [759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15912026-10-01 09:33:46.586 UTC [760] ERROR: relation "goose_db_version" does not exist at character 3615922026-10-01 09:33:46.586 UTC [760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15932026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)15942026/10/01 09:33:46 OK 20260905000000_add_claims.sql (5.46ms)1595--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.67s)1596=== CONT TestSweepSkipsRowsLockedByPush15972026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.35ms)15982026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (3.11ms)15992026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000016002026/10/01 09:33:46 OK 20241026095416_initial_model.sql (11.1ms)16012026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)16022026/10/01 09:33:46 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTk2YmY4ZDktZTg3OC00NmQ5LTgzMmItNTI2ZDAyMWE2YTMxLjAyZmRhZTg1LTNlNTYtNGMyMi05YjdmLWM5YzA4NDJlOGVlM3gxNzkwODQ3MjI2MDQ3Njg1Mzg3 parts=1216032026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.88ms)16042026/10/01 09:33:46 OK 20241026095416_initial_model.sql (11.29ms)16052026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures16062026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.83ms)16072026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.76ms)16082026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)16092026/10/01 09:33:46 OK 3_commit_push.sql (2.2ms)16102026/10/01 09:33:46 goose: up to current file version: 316112026-10-01 09:33:46.610 UTC [765] ERROR: relation "goose_db_version" does not exist at character 3616122026-10-01 09:33:46.610 UTC [765] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1613--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.13s)1614=== CONT TestDeduplicatedObjectsRecordedAsPending16152026/10/01 09:33:46 OK 20251218171726_add_pins.sql (4.02ms)16162026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)16172026/10/01 09:33:46 OK 20260905000000_add_claims.sql (6.45ms)16182026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (8.32ms)16192026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.25ms)16202026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.45ms)16212026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (3.17ms)16222026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000016232026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.92ms)16242026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.23ms)1625--- PASS: TestReadProxyNarinfo (0.69s)1626=== CONT TestFailedS3DeleteKeepsTombstone16272026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (10.31ms)16282026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000016292026/10/01 09:33:46 OK 2_object_stats_trigger.sql (13.19ms)16302026/10/01 09:33:46 OK 20241026095416_initial_model.sql (20.12ms)16312026/10/01 09:33:46 OK 1_commit_pending_closure.sql (4.7ms)16322026/10/01 09:33:46 OK 3_commit_push.sql (2.46ms)16332026/10/01 09:33:46 goose: up to current file version: 316342026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)16352026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.27ms)16362026/10/01 09:33:46 OK 3_commit_push.sql (1.52ms)16372026/10/01 09:33:46 goose: up to current file version: 316382026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.68ms)16392026-10-01 09:33:46.650 UTC [770] ERROR: relation "goose_db_version" does not exist at character 3616402026-10-01 09:33:46.650 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16412026-10-01 09:33:46.651 UTC [771] ERROR: relation "goose_db_version" does not exist at character 3616422026-10-01 09:33:46.651 UTC [771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16432026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)16442026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.73ms)16452026-10-01 09:33:46.657 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3616462026-10-01 09:33:46.657 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16472026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.15ms)16482026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.8ms)16492026/10/01 09:33:46 goose: successfully migrated database to version: 202609231200001650--- PASS: TestReadRedirectNar (0.67s)1651=== CONT TestPushDedupSurvivesConcurrentGC16522026/10/01 09:33:46 OK 1_commit_pending_closure.sql (3.55ms)16532026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.75ms)16542026/10/01 09:33:46 OK 20241026095416_initial_model.sql (11.04ms)16552026/10/01 09:33:46 OK 20241026095416_initial_model.sql (11.33ms)16562026/10/01 09:33:46 OK 3_commit_push.sql (2.01ms)16572026/10/01 09:33:46 goose: up to current file version: 316582026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)16592026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)16602026/10/01 09:33:46 OK 20251218171726_add_pins.sql (4.89ms)16612026/10/01 09:33:46 OK 20241026095416_initial_model.sql (10.94ms)16622026/10/01 09:33:46 OK 20251218171726_add_pins.sql (5.08ms)16632026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)16642026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)16652026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)16662026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.46ms)16672026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.37ms)16682026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.37ms)16692026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.62ms)16702026-10-01 09:33:46.686 UTC [775] ERROR: relation "goose_db_version" does not exist at character 3616712026-10-01 09:33:46.686 UTC [775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16722026/10/01 09:33:46 INFO Starting HTTP server address=127.0.0.1:3866516732026/10/01 09:33:46 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2456754019/001/proxy.sock16742026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)16752026/10/01 09:33:46 WARN mTLS auth: subject not in bound subjects subject="CN=someone"16762026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.95ms)16772026/10/01 09:33:46 INFO Shutdown signal received, draining in-flight requests timeout=10s16782026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.41ms)16792026/10/01 09:33:46 goose: successfully migrated database to version: 202609231200001680--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.60s)1681=== CONT TestForceGCDuringPushOffersSweptObject1682=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1683=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1684=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1685=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1686=== CONT TestGCMetrics16872026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.89ms)16882026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000016892026/10/01 09:33:46 OK 1_commit_pending_closure.sql (10.83ms)16902026/10/01 09:33:46 OK 20260905000000_add_claims.sql (12.54ms)16912026/10/01 09:33:46 OK 1_commit_pending_closure.sql (11.54ms)16922026/10/01 09:33:46 OK 2_object_stats_trigger.sql (4.07ms)16932026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.34ms)16942026/10/01 09:33:46 OK 3_commit_push.sql (2.02ms)16952026/10/01 09:33:46 goose: up to current file version: 316962026/10/01 09:33:46 OK 3_commit_push.sql (2.25ms)16972026/10/01 09:33:46 goose: up to current file version: 316982026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (8.22ms)16992026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.94ms)17002026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017012026/10/01 09:33:46 OK 20241026095416_initial_model.sql (12.66ms)17022026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.56ms)17032026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)17042026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.76ms)17052026-10-01 09:33:46.717 UTC [778] ERROR: relation "goose_db_version" does not exist at character 3617062026-10-01 09:33:46.717 UTC [778] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17072026/10/01 09:33:46 OK 3_commit_push.sql (1.6ms)17082026/10/01 09:33:46 goose: up to current file version: 317092026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.88ms)17102026-10-01 09:33:46.719 UTC [779] ERROR: relation "goose_db_version" does not exist at character 3617112026-10-01 09:33:46.719 UTC [779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1712--- PASS: TestReadProxyDisabled (0.57s)1713=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection17142026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4ms)17152026-10-01 09:33:46.725 UTC [780] ERROR: relation "goose_db_version" does not exist at character 3617162026-10-01 09:33:46.725 UTC [780] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17172026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.32ms)17182026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.64ms)17192026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.51ms)17202026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017212026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.59ms)17222026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.7ms)17232026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.15ms)17242026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.57ms)17252026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)17262026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)17272026/10/01 09:33:46 OK 3_commit_push.sql (1.75ms)17282026/10/01 09:33:46 goose: up to current file version: 317292026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.95ms)17302026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.73ms)17312026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)17322026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)17332026/10/01 09:33:46 OK 20241026095416_initial_model.sql (11.55ms)17342026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)17352026-10-01 09:33:46.746 UTC [783] ERROR: relation "goose_db_version" does not exist at character 3617362026-10-01 09:33:46.746 UTC [783] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17372026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.95ms)17382026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.94ms)17392026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.63ms)17402026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.96ms)17412026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.25ms)17422026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.67ms)17432026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017442026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.98ms)17452026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017462026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)17472026/10/01 09:33:46 OK 1_commit_pending_closure.sql (3.08ms)1748--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.60s)1749=== CONT TestGCBugBareHashReferences17502026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.92ms)17512026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.67ms)17522026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.58ms)17532026/10/01 09:33:46 OK 3_commit_push.sql (1.76ms)17542026/10/01 09:33:46 goose: up to current file version: 317552026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.6ms)17562026/10/01 09:33:46 OK 3_commit_push.sql (2.04ms)17572026/10/01 09:33:46 goose: up to current file version: 317582026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.32ms)17592026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.66ms)17602026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)17612026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.43ms)17622026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017632026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.12ms)17642026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.64ms)17652026/10/01 09:33:46 OK 2_object_stats_trigger.sql (2.32ms)17662026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)17672026/10/01 09:33:46 OK 3_commit_push.sql (1.71ms)17682026/10/01 09:33:46 goose: up to current file version: 317692026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.89ms)17702026-10-01 09:33:46.777 UTC [786] ERROR: relation "goose_db_version" does not exist at character 3617712026-10-01 09:33:46.777 UTC [786] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17722026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.4ms)17732026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.16ms)17742026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017752026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.24ms)17762026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.69ms)17772026/10/01 09:33:46 OK 3_commit_push.sql (1.26ms)17782026/10/01 09:33:46 goose: up to current file version: 317792026-10-01 09:33:46.796 UTC [787] ERROR: relation "goose_db_version" does not exist at character 3617802026-10-01 09:33:46.796 UTC [787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17812026/10/01 09:33:46 OK 20241026095416_initial_model.sql (16.53ms)17822026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)17832026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.15ms)17842026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)17852026/10/01 09:33:46 OK 20241026095416_initial_model.sql (8.45ms)17862026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.87ms)17872026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)17882026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (1.9ms)17892026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.78ms)17902026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.19ms)17912026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000017922026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.4ms)17932026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)17942026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.81ms)17952026/10/01 09:33:46 OK 3_commit_push.sql (1.26ms)17962026/10/01 09:33:46 goose: up to current file version: 317972026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.97ms)1798--- PASS: TestPresentReportsOnlyClosureRoots (0.57s)1799=== CONT TestLeadEndsOnShutdown18002026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (1.98ms)18012026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (1.88ms)18022026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000018032026/10/01 09:33:46 OK 1_commit_pending_closure.sql (1.98ms)18042026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.3ms)18052026-10-01 09:33:46.832 UTC [789] ERROR: relation "goose_db_version" does not exist at character 3618062026-10-01 09:33:46.832 UTC [789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18072026/10/01 09:33:46 OK 3_commit_push.sql (1.38ms)18082026/10/01 09:33:46 goose: up to current file version: 318092026/10/01 09:33:46 WARN readiness check failed error="closed pool"1810--- PASS: TestService_readinessHandler (0.53s)1811=== CONT TestLeadElectsOneAndHandsOver18122026/10/01 09:33:46 OK 20241026095416_initial_model.sql (9.9ms)18132026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)18142026/10/01 09:33:46 OK 20251218171726_add_pins.sql (2.55ms)18152026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)18162026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.06ms)18172026-10-01 09:33:46.859 UTC [794] ERROR: relation "goose_db_version" does not exist at character 3618182026-10-01 09:33:46.859 UTC [794] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18192026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.2ms)18202026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.14ms)18212026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000018222026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.54ms)18232026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.93ms)18242026/10/01 09:33:46 OK 3_commit_push.sql (1.55ms)18252026/10/01 09:33:46 goose: up to current file version: 318262026/10/01 09:33:46 OK 20241026095416_initial_model.sql (10.6ms)18272026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)18282026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.59ms)18292026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)18302026/10/01 09:33:46 OK 20260905000000_add_claims.sql (4.7ms)18312026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.91ms)18322026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.64ms)18332026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000018342026/10/01 09:33:46 OK 1_commit_pending_closure.sql (3.26ms)1835--- PASS: TestService_healthCheckHandler (0.51s)1836=== CONT TestClientErrorHandling1837=== RUN TestClientErrorHandling/InvalidStorePath1838=== PAUSE TestClientErrorHandling/InvalidStorePath1839=== RUN TestClientErrorHandling/InvalidAuthToken1840=== PAUSE TestClientErrorHandling/InvalidAuthToken1841=== RUN TestClientErrorHandling/ServerNotAvailable1842=== PAUSE TestClientErrorHandling/ServerNotAvailable1843=== CONT TestPinProtectsFromGC18442026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.79ms)18452026/10/01 09:33:46 OK 3_commit_push.sql (1.47ms)18462026/10/01 09:33:46 goose: up to current file version: 318472026-10-01 09:33:46.913 UTC [796] ERROR: relation "goose_db_version" does not exist at character 3618482026-10-01 09:33:46.913 UTC [796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18492026-10-01 09:33:46.922 UTC [798] ERROR: relation "goose_db_version" does not exist at character 3618502026-10-01 09:33:46.922 UTC [798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18512026/10/01 09:33:46 OK 20241026095416_initial_model.sql (8.78ms)18522026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)18532026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.92ms)18542026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (12.59ms)18552026/10/01 09:33:46 OK 20241026095416_initial_model.sql (17.93ms)18562026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)18572026/10/01 09:33:46 OK 20260905000000_add_claims.sql (3.32ms)18582026/10/01 09:33:46 OK 20251218171726_add_pins.sql (3.67ms)18592026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (3.07ms)18602026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.37ms)18612026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000018622026/10/01 09:33:46 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)18632026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.32ms)18642026/10/01 09:33:46 OK 20260905000000_add_claims.sql (2.44ms)18652026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.65ms)18662026/10/01 09:33:46 OK 3_commit_push.sql (1.04ms)18672026/10/01 09:33:46 goose: up to current file version: 318682026/10/01 09:33:46 OK 20260920000000_drop_claims.sql (2.19ms)18692026/10/01 09:33:46 OK 20260923120000_add_pushes.sql (2.04ms)18702026/10/01 09:33:46 goose: successfully migrated database to version: 2026092312000018712026/10/01 09:33:46 OK 1_commit_pending_closure.sql (2.52ms)18722026/10/01 09:33:46 OK 2_object_stats_trigger.sql (1.77ms)18732026/10/01 09:33:46 OK 3_commit_push.sql (883.26µs)18742026/10/01 09:33:46 goose: up to current file version: 31875--- PASS: TestObjectStatsTrigger (0.57s)1876=== CONT TestClientSharedPathCommittedMidPush18772026-10-01 09:33:46.985 UTC [799] ERROR: relation "goose_db_version" does not exist at character 3618782026-10-01 09:33:46.985 UTC [799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18792026/10/01 09:33:46 INFO Received uploads request method=POST path=/api/pending_closures18802026/10/01 09:33:46 OK 20241026095416_initial_model.sql (7.9ms)18812026/10/01 09:33:46 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)18822026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.93ms)18832026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)18842026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.61ms)18852026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.49ms)18862026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.64ms)18872026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000018882026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.37ms)18892026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.59ms)18902026/10/01 09:33:47 OK 3_commit_push.sql (1.15ms)18912026/10/01 09:33:47 goose: up to current file version: 31892--- PASS: TestMetricsInventory (0.59s)1893=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock18942026/10/01 09:33:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18952026/10/01 09:33:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1896--- PASS: TestService_NativeMTLS (0.60s)1897=== CONT TestClientWithDependencies18982026-10-01 09:33:47.080 UTC [806] ERROR: relation "goose_db_version" does not exist at character 3618992026-10-01 09:33:47.080 UTC [806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19002026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.72ms)19012026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)19022026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.43ms)19032026/10/01 09:33:47 INFO Received cleanup request method=DELETE path=/api/pending_closures19042026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)19052026/10/01 09:33:47 INFO Aborted multipart uploads count=119062026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.64ms)19072026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.24ms)1908--- PASS: TestMultipartCleanup (0.67s)1909=== CONT TestClientMultipleUploads19102026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.88ms)19112026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000019122026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.46ms)1913--- PASS: TestGCEndsOnShutdown (0.61s)1914=== CONT TestClientFallsBackToClosures19152026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.38ms)19162026/10/01 09:33:47 OK 3_commit_push.sql (1.41ms)19172026/10/01 09:33:47 goose: up to current file version: 31918=== NAME TestNARDeduplicationMetadataUploadBug1919 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3990832766/001/store/fzpwdqafdapx1n9l9ld5g59391q1dgdz-file1.txt19202026/10/01 09:33:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19212026/10/01 09:33:47 WARN Refused reserved pin name=worker-x86_64-linux19222026-10-01 09:33:47.147 UTC [829] ERROR: relation "goose_db_version" does not exist at character 3619232026-10-01 09:33:47.147 UTC [829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19242026/10/01 09:33:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19252026/10/01 09:33:47 INFO Received create pin request method=POST path=/api/pins/my-app19262026/10/01 09:33:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1927--- PASS: TestCreatePin_ReservedPins (0.87s)1928=== CONT TestClientPushesUseOnePush19292026-10-01 09:33:47.149 UTC [830] ERROR: relation "goose_db_version" does not exist at character 3619302026-10-01 09:33:47.149 UTC [830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19312026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.27ms)19322026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.31ms)19332026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)19342026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)19352026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.53ms)19362026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.11ms)19372026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)19382026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures19392026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)19402026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.81ms)19412026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.55ms)19422026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.41ms)19432026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.6ms)19442026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000019452026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.89ms)19462026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.51ms)19472026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (3.18ms)19482026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000019492026/10/01 09:33:47 OK 2_object_stats_trigger.sql (2.06ms)1950--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.65s)1951=== CONT TestClientIntegration19522026/10/01 09:33:47 OK 3_commit_push.sql (2.27ms)19532026/10/01 09:33:47 goose: up to current file version: 319542026/10/01 09:33:47 OK 1_commit_pending_closure.sql (3.13ms)19552026/10/01 09:33:47 OK 2_object_stats_trigger.sql (2.06ms)19562026/10/01 09:33:47 OK 3_commit_push.sql (2.15ms)19572026/10/01 09:33:47 goose: up to current file version: 319582026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes19592026-10-01 09:33:47.223 UTC [870] ERROR: relation "goose_db_version" does not exist at character 3619602026-10-01 09:33:47.223 UTC [870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19612026/10/01 09:33:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19622026/10/01 09:33:47 INFO Uploading fzpwdqafdapx1n9l9ld5g59391q1dgdz-file1.txt (160B)19632026-10-01 09:33:47.227 UTC [871] ERROR: relation "goose_db_version" does not exist at character 3619642026-10-01 09:33:47.227 UTC [871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19652026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19662026/10/01 09:33:47 WARN Failed to register uploaded object key=fzpwdqafdapx1n9l9ld5g59391q1dgdz.ls error="server returned 404: 404 page not found\n"19672026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19682026/10/01 09:33:47 INFO Signed narinfos id=1 count=119692026/10/01 09:33:47 INFO Uploading 1 narinfos19702026/10/01 09:33:47 INFO Aborted multipart uploads count=019712026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.35ms)19722026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)19732026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete19742026/10/01 09:33:47 WARN Failed to register uploaded object key=fzpwdqafdapx1n9l9ld5g59391q1dgdz.narinfo error="server returned 404: 404 page not found\n"19752026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.46ms)19762026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.68ms)19772026-10-01 09:33:47.242 UTC [873] ERROR: relation "goose_db_version" does not exist at character 3619782026-10-01 09:33:47.242 UTC [873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19792026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period19802026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)19812026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (10.47ms)19822026/10/01 09:33:47 OK 20251218171726_add_pins.sql (11ms)19832026/10/01 09:33:47 INFO Upload complete. (78ms)19842026/10/01 09:33:47 INFO Aborted multipart uploads count=019852026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.91ms)1986=== NAME TestNARDeduplicationMetadataUploadBug1987 metadata_upload_test.go:54: Retrieved narinfo from S3:1988 StorePath: /build/TestNARDeduplicationMetadataUploadBug3990832766/001/store/fzpwdqafdapx1n9l9ld5g59391q1dgdz-file1.txt1989 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1990 Compression: zstd1991 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1992 NarSize: 1601993 References: 1994 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19952026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)19972026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.21ms)1998 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1999 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2000 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}20012026/10/01 09:33: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=020022026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.3ms)20032026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000020042026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.41ms)20052026/10/01 09:33:47 INFO Vacuumed table table=pending_closures20062026/10/01 09:33:47 INFO Vacuumed table table=pending_objects20072026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads20082026/10/01 09:33:47 INFO Vacuumed table table=closures20092026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.29ms)20102026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.47ms)20112026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures20122026/10/01 09:33:47 OK 2_object_stats_trigger.sql (2.26ms)20132026/10/01 09:33:47 INFO Vacuumed table table=objects20142026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.75ms)20152026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.76ms)20162026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000020172026/10/01 09:33:47 OK 3_commit_push.sql (874.62µs)20182026/10/01 09:33:47 goose: up to current file version: 320192026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)20202026/10/01 09:33:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=020212026/10/01 09:33:47 OK 1_commit_pending_closure.sql (1.61ms)20222026/10/01 09:33:47 INFO Aborted multipart uploads count=020232026/10/01 09:33:47 INFO Vacuumed table table=pending_closures20242026/10/01 09:33:47 OK 2_object_stats_trigger.sql (932.41µs)2025=== NAME TestOrphanedObjectsGC2026 orphaned_objects_gc_test.go:290: GC Test Summary:2027 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2028 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2029 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)20302026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.79ms)2031 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2032 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2033--- PASS: TestOrphanedObjectsGC (0.88s)20342026/10/01 09:33:47 INFO Vacuumed table table=pending_objects2035=== CONT TestPushWaitsForSweepHoldingRow20362026/10/01 09:33:47 OK 3_commit_push.sql (1.42ms)20372026/10/01 09:33:47 goose: up to current file version: 320382026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads20392026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period20402026/10/01 09:33:47 INFO Vacuumed table table=closures20412026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)20422026/10/01 09:33:47 INFO Vacuumed table table=objects2043--- PASS: TestGCSweepDeliversEachKeyOnce (0.71s)2044=== CONT TestSweepRechecksPendingAfterLocking20452026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.72ms)20462026/10/01 09:33:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=020472026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.76ms)20482026/10/01 09:33:47 INFO Vacuumed table table=pending_closures20492026/10/01 09:33:47 INFO Vacuumed table table=pending_objects20502026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads20512026/10/01 09:33:47 INFO Vacuumed table table=closures20522026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.4ms)20532026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000020542026-10-01 09:33:47.281 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3620552026-10-01 09:33:47.281 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20562026/10/01 09:33:47 INFO Vacuumed table table=objects2057--- PASS: TestSweepSkipsRowsLockedByPush (0.69s)20582026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.46ms)2059=== CONT TestGetExistingObjectsLocksRows20602026/10/01 09:33:47 OK 2_object_stats_trigger.sql (976.79µs)20612026/10/01 09:33:47 OK 3_commit_push.sql (1.24ms)20622026/10/01 09:33:47 goose: up to current file version: 320632026/10/01 09:33:47 INFO Aborted multipart uploads count=020642026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures20652026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period20662026/10/01 09:33: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=020672026/10/01 09:33:47 INFO Vacuumed table table=pending_closures2068--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.68s)2069=== CONT TestRegisterCompletedObjectNeedsPendingRow20702026/10/01 09:33:47 INFO Vacuumed table table=pending_objects20712026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads20722026/10/01 09:33:47 INFO Vacuumed table table=closures20732026/10/01 09:33:47 INFO Vacuumed table table=objects20742026/10/01 09:33:47 OK 20241026095416_initial_model.sql (14.32ms)20752026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)2076=== NAME TestNARDeduplicationMetadataUploadBug2077 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3990832766/001/store/sl04vvnzx1as4j5kk9jah5mi642s8qx9-file2.txt20782026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.47ms)2079--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.12s)2080=== CONT TestService_RequireScope_OIDC20812026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures2082--- PASS: TestGCSweepSkipsPendingObjects (0.73s)2083=== CONT TestCacheStatsHandler20842026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)20852026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.2ms)20862026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.22ms)20872026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.72ms)20882026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000020892026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.25ms)20902026/10/01 09:33:47 OK 2_object_stats_trigger.sql (2.27ms)20912026/10/01 09:33:47 OK 3_commit_push.sql (1.46ms)20922026/10/01 09:33:47 goose: up to current file version: 320932026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures20942026/10/01 09:33:47 INFO Aborted multipart uploads count=020952026-10-01 09:33:47.376 UTC [933] ERROR: relation "goose_db_version" does not exist at character 3620962026-10-01 09:33:47.376 UTC [933] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20972026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period20982026/10/01 09:33:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37245/oidc20992026/10/01 09:33: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=021002026/10/01 09:33:47 INFO Vacuumed table table=pending_closures21012026/10/01 09:33:47 INFO Vacuumed table table=pending_objects21022026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads21032026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes21042026/10/01 09:33:47 INFO Vacuumed table table=closures21052026/10/01 09:33:47 INFO Vacuumed table table=objects21062026-10-01 09:33:47.384 UTC [951] ERROR: relation "goose_db_version" does not exist at character 3621072026-10-01 09:33:47.384 UTC [951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21082026/10/01 09:33:47 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21092026/10/01 09:33:47 INFO Aborted multipart uploads count=02110--- PASS: TestGCMetrics (0.70s)2111=== CONT TestCacheConfigHandler2112=== RUN TestCacheConfigHandler/full_config,_no_issuer2113=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2114=== RUN TestCacheConfigHandler/no_cache_url_configured2115=== PAUSE TestCacheConfigHandler/no_cache_url_configured2116=== RUN TestCacheConfigHandler/no_signing_keys2117=== PAUSE TestCacheConfigHandler/no_signing_keys2118=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2119=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2120=== CONT TestClientCADerivations21212026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period21222026/10/01 09:33:47 OK 20241026095416_initial_model.sql (7.69ms)21232026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21242026/10/01 09:33:47 INFO Signed narinfos id=2 count=121252026/10/01 09:33:47 WARN Failed to register uploaded object key=sl04vvnzx1as4j5kk9jah5mi642s8qx9.ls error="server returned 404: 404 page not found\n"21262026/10/01 09:33:47 INFO Uploading 1 narinfos21272026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)21282026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.12ms)21292026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures21302026-10-01 09:33:47.398 UTC [956] ERROR: relation "goose_db_version" does not exist at character 3621312026-10-01 09:33:47.398 UTC [956] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21322026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.65ms)21332026/10/01 09:33:47 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."21342026/10/01 09:33:47 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."21352026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/2/complete21362026/10/01 09:33:47 WARN Failed to register uploaded object key=sl04vvnzx1as4j5kk9jah5mi642s8qx9.narinfo error="server returned 404: 404 page not found\n"21372026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)21382026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)2139--- PASS: TestFailedS3DeleteKeepsTombstone (0.77s)2140=== CONT TestService_ReadScope_PublicByDefault21412026/10/01 09:33:47 INFO Upload complete. (54ms)2142=== NAME TestNARDeduplicationMetadataUploadBug21432026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.37ms)2144 metadata_upload_test.go:76: Retrieved narinfo from S3:21452026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.24ms)2146 StorePath: /build/TestNARDeduplicationMetadataUploadBug3990832766/001/store/sl04vvnzx1as4j5kk9jah5mi642s8qx9-file2.txt2147 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2148 Compression: zstd2149 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2150 NarSize: 1602151 References: 2152 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21532026-10-01 09:33:47.406 UTC [958] ERROR: relation "goose_db_version" does not exist at character 3621542026-10-01 09:33:47.406 UTC [958] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2155 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2156 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2157 {"version":1,"root":{"type":"regular","size":44}}21582026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (3.68ms)21592026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)21602026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.4ms)21612026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000021622026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.56ms)21632026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.32ms)2164--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)2165=== CONT TestService_ReadAuthMiddleware21662026/10/01 09:33:47 OK 1_commit_pending_closure.sql (3.42ms)21672026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)21682026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.86ms)21692026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.44ms)21702026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.76ms)21712026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000021722026/10/01 09:33:47 OK 3_commit_push.sql (1.93ms)21732026/10/01 09:33:47 goose: up to current file version: 321742026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.33ms)21752026-10-01 09:33:47.419 UTC [961] ERROR: relation "goose_db_version" does not exist at character 3621762026-10-01 09:33:47.419 UTC [961] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21772026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.75ms)21782026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.79ms)21792026/10/01 09:33:47 OK 2_object_stats_trigger.sql (2.32ms)21802026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)21812026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)21822026/10/01 09:33:47 OK 3_commit_push.sql (1.56ms)21832026/10/01 09:33:47 goose: up to current file version: 321842026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.88ms)21852026/10/01 09:33:47 OK 20251218171726_add_pins.sql (4.2ms)21862026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.75ms)21872026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)21882026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.72ms)21892026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000021902026/10/01 09:33:47 OK 1_commit_pending_closure.sql (3.8ms)21912026/10/01 09:33:47 OK 20260905000000_add_claims.sql (4.94ms)21922026/10/01 09:33:47 OK 20241026095416_initial_model.sql (10.63ms)21932026/10/01 09:33:47 OK 2_object_stats_trigger.sql (2.13ms)21942026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)21952026/10/01 09:33:47 OK 3_commit_push.sql (1.64ms)21962026/10/01 09:33:47 goose: up to current file version: 321972026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (3.98ms)21982026/10/01 09:33:47 INFO Aborted multipart uploads count=021992026/10/01 09:33:47 INFO lead: acquired remote=192.0.2.1:123422002026/10/01 09:33:47 INFO lead: released remote=192.0.2.1:12342201--- PASS: TestLeadEndsOnShutdown (0.62s)2202=== CONT TestService_AuthMiddleware_OIDC22032026/10/01 09:33:47 OK 20251218171726_add_pins.sql (12.09ms)22042026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (11.49ms)22052026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000022062026/10/01 09:33:47 OK 1_commit_pending_closure.sql (3.82ms)22072026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)22082026/10/01 09:33:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022092026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.6ms)22102026/10/01 09:33:47 OK 3_commit_push.sql (1.61ms)22112026/10/01 09:33:47 goose: up to current file version: 322122026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.13ms)22132026/10/01 09:33:47 INFO Vacuumed table table=pending_closures22142026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.28ms)22152026/10/01 09:33:47 INFO Vacuumed table table=pending_objects22162026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads22172026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.53ms)22182026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000022192026/10/01 09:33:47 INFO Vacuumed table table=closures22202026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.83ms)22212026/10/01 09:33:47 INFO Vacuumed table table=objects22222026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.94ms)22232026/10/01 09:33:47 OK 3_commit_push.sql (1.63ms)22242026/10/01 09:33:47 goose: up to current file version: 322252026/10/01 09:33:47 INFO lead: acquired remote=192.0.2.1:123422262026-10-01 09:33:47.474 UTC [965] ERROR: relation "goose_db_version" does not exist at character 3622272026-10-01 09:33:47.474 UTC [965] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22282026/10/01 09:33:47 INFO Aborted multipart uploads count=022292026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period22302026/10/01 09:33: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=022312026/10/01 09:33:47 INFO Vacuumed table table=pending_closures22322026/10/01 09:33:47 INFO Vacuumed table table=pending_objects22332026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads22342026/10/01 09:33:47 INFO Vacuumed table table=closures22352026/10/01 09:33:47 INFO Vacuumed table table=objects22362026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.99ms)2237--- PASS: TestPushDedupSurvivesConcurrentGC (0.83s)2238=== CONT TestService_AuthMiddleware_MTLSBoundSubjects22392026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)22402026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.86ms)22412026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)22422026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.28ms)22432026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.24ms)22442026-10-01 09:33:47.505 UTC [969] ERROR: relation "goose_db_version" does not exist at character 3622452026-10-01 09:33:47.505 UTC [969] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22462026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.69ms)22472026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000022482026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.12ms)22492026-10-01 09:33:47.510 UTC [970] ERROR: relation "goose_db_version" does not exist at character 3622502026-10-01 09:33:47.510 UTC [970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22512026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.89ms)22522026-10-01 09:33:47.513 UTC [972] ERROR: relation "goose_db_version" does not exist at character 3622532026-10-01 09:33:47.513 UTC [972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22542026/10/01 09:33:47 OK 3_commit_push.sql (2.57ms)22552026/10/01 09:33:47 goose: up to current file version: 322562026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.6ms)22572026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)22582026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.57ms)22592026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.36ms)22602026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)22612026/10/01 09:33:47 OK 20241026095416_initial_model.sql (7.44ms)22622026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)22632026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.81ms)22642026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)22652026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.6ms)22662026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.73ms)22672026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)22682026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.48ms)22692026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (2.35ms)22702026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.91ms)22712026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.08ms)22722026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000022732026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.35ms)22742026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.59ms)22752026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (2.22ms)22762026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.72ms)22772026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.97ms)22782026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000022792026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.73ms)22802026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (3.06ms)22812026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000022822026/10/01 09:33:47 OK 3_commit_push.sql (1.8ms)22832026/10/01 09:33:47 goose: up to current file version: 322842026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.77ms)22852026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.12ms)22862026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.65ms)22872026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.37ms)22882026/10/01 09:33:47 OK 3_commit_push.sql (1.99ms)22892026/10/01 09:33:47 goose: up to current file version: 322902026/10/01 09:33:47 OK 3_commit_push.sql (1.66ms)22912026/10/01 09:33:47 goose: up to current file version: 322922026/10/01 09:33:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40907/oidc22932026-10-01 09:33:47.569 UTC [1009] ERROR: relation "goose_db_version" does not exist at character 3622942026-10-01 09:33:47.569 UTC [1009] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2295=== NAME TestPinProtectsFromGC2296 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2123900093/001/store/2y1wcp0yjp2plvamrm5l7964sh2kl4r2-pinned-file.txt2297 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2123900093/001/store/044f433vlb2y9b4lyknwxm8brvjk8l95-unpinned-file.txt22982026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.27ms)22992026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)23002026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.25ms)23012026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)23022026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.96ms)23032026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.92ms)23042026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.79ms)23052026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000023062026/10/01 09:33:47 OK 1_commit_pending_closure.sql (1.9ms)23072026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.31ms)23082026/10/01 09:33:47 OK 3_commit_push.sql (1.24ms)23092026/10/01 09:33:47 goose: up to current file version: 32310--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.89s)2311=== CONT TestService_AuthMiddleware_MTLSProxyHeader23122026/10/01 09:33:47 INFO lead: released remote=192.0.2.1:123423132026-10-01 09:33:47.632 UTC [1084] ERROR: relation "goose_db_version" does not exist at character 3623142026-10-01 09:33:47.632 UTC [1084] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23152026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.75ms)2316=== NAME TestClientWithDependencies23172026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)2318 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3620199767/001/store/ydy1y3flvd533an5mp146fxnw8cda97d-test-script23192026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.73ms)23202026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)23212026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.95ms)23222026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.48ms)23232026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.44ms)23242026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000023252026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.3ms)23262026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.14ms)2327--- PASS: TestGCBugBareHashReferences (0.91s)23282026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes2329=== CONT TestProxyWriteTimeout/narinfo2330=== CONT TestProxyWriteTimeout/unknown_size2331=== CONT TestProxyWriteTimeout/10_GiB_nar2332=== CONT TestProxyWriteTimeout/1_GiB_nar2333--- PASS: TestProxyWriteTimeout (0.00s)2334 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2335 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2336 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2337 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2338=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23392026/10/01 09:33:47 INFO Received uploads request method=POST path=/2340=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23412026/10/01 09:33:47 INFO Received request for more parts method=POST path=/2342=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23432026/10/01 09:33:47 OK 3_commit_push.sql (1.12ms)23442026/10/01 09:33:47 goose: up to current file version: 323452026/10/01 09:33:47 INFO Received complete multipart upload request method=POST path=/2346=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23472026/10/01 09:33:47 INFO Received uploads request method=POST path=/2348--- PASS: TestUploadHandlersRejectInvalidKeys (0.12s)2349 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2350 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2351 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2352 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2353=== CONT TestIsValidUploadKey/narinfo2354=== CONT TestIsValidUploadKey/unknown_type2355=== CONT TestIsValidUploadKey/empty_key2356=== CONT TestIsValidUploadKey/absolute2357=== CONT TestIsValidUploadKey/traversal_nar2358=== CONT TestIsValidUploadKey/traversal2359=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2360=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2361=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2362=== CONT TestIsValidUploadKey/index.html2363=== CONT TestIsValidUploadKey/nix-cache-info2364=== CONT TestIsValidUploadKey/realisation_plus_in_output2365=== CONT TestIsValidUploadKey/realisation2366=== CONT TestIsValidUploadKey/build_log_equals2367=== CONT TestIsValidUploadKey/build_log_question_mark2368=== CONT TestIsValidUploadKey/build_log_plus_in_name2369=== CONT TestIsValidUploadKey/build_log_home-manager_file2370=== CONT TestIsValidUploadKey/build_log2371=== CONT TestIsValidUploadKey/listing2372=== CONT TestIsValidUploadKey/nar_plain2373=== CONT TestIsValidUploadKey/nar_xz2374=== CONT TestIsValidUploadKey/nar_zst2375=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23762026/10/01 09:33:47 INFO Received uploads request method=POST path=/2377--- PASS: TestIsValidUploadKey (0.13s)2378 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2379 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2380 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2381 --- PASS: TestIsValidUploadKey/absolute (0.00s)2382 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2383 --- PASS: TestIsValidUploadKey/traversal (0.00s)2384 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2385 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2386 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2387 --- PASS: TestIsValidUploadKey/index.html (0.00s)2388 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2389 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2390 --- PASS: TestIsValidUploadKey/realisation (0.00s)2391 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2392 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2393 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2394 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2395 --- PASS: TestIsValidUploadKey/build_log (0.00s)2396 --- PASS: TestIsValidUploadKey/listing (0.00s)2397 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2398 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2399 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)24002026/10/01 09:33:47 INFO lead: acquired remote=192.0.2.1:123424012026/10/01 09:33:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24022026/10/01 09:33:47 INFO Uploading 2y1wcp0yjp2plvamrm5l7964sh2kl4r2-pinned-file.txt (128B)24032026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"24042026/10/01 09:33:47 INFO lead: released remote=192.0.2.1:12342405--- PASS: TestLeadElectsOneAndHandsOver (0.84s)2406=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24072026/10/01 09:33:47 INFO Received request for more parts method=POST path=/24082026/10/01 09:33:47 WARN Failed to register uploaded object key=2y1wcp0yjp2plvamrm5l7964sh2kl4r2.ls error="server returned 404: 404 page not found\n"24092026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24102026/10/01 09:33:47 INFO Signed narinfos id=1 count=124112026/10/01 09:33:47 INFO Uploading 1 narinfos24122026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete24132026/10/01 09:33:47 WARN Failed to register uploaded object key=2y1wcp0yjp2plvamrm5l7964sh2kl4r2.narinfo error="server returned 404: 404 page not found\n"2414=== NAME TestClientMultipleUploads2415 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3815968272/001/store/xg410fi2mhkv891108b4cbx5sfmimiks-test-file-0.txt2416=== NAME TestClientWithDependencies2417 client_integration_test.go:615: Found 1 dependencies (including self)24182026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes24192026/10/01 09:33:47 INFO Upload complete. (68ms)24202026/10/01 09:33:47 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)24212026/10/01 09:33:47 INFO Uploading 3cg5mbdnrq4yqb174w5ybdij9v7qkkbn-top (224B)24222026/10/01 09:33:47 INFO Uploading 67dcncl1xzra455nwc3qvazr3xkrnlnq-shared-dep (136B)24232026-10-01 09:33:47.699 UTC [1226] ERROR: relation "goose_db_version" does not exist at character 3624242026-10-01 09:33:47.699 UTC [1226] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24252026/10/01 09:33:47 WARN Failed to register uploaded object key=67dcncl1xzra455nwc3qvazr3xkrnlnq.ls error="server returned 404: 404 page not found\n"24262026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24272026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/0xkyqrgmb84lac6wjbmcpb75mq9fhxwn2h1jn1rmkjaqdsg264ma.nar.zst error="server returned 404: 404 page not found\n"24282026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24292026/10/01 09:33:47 WARN Failed to register uploaded object key=3cg5mbdnrq4yqb174w5ybdij9v7qkkbn.ls error="server returned 404: 404 page not found\n"24302026/10/01 09:33:47 INFO Signed narinfos id=1 count=224312026/10/01 09:33:47 INFO Uploading 2 narinfos24322026/10/01 09:33:47 WARN Failed to register uploaded object key=3cg5mbdnrq4yqb174w5ybdij9v7qkkbn.narinfo error="server returned 404: 404 page not found\n"24332026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete24342026/10/01 09:33:47 WARN Failed to register uploaded object key=67dcncl1xzra455nwc3qvazr3xkrnlnq.narinfo error="server returned 404: 404 page not found\n"24352026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.05ms)24362026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)24372026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.34ms)24382026/10/01 09:33:47 INFO Upload complete. (69ms)2439=== NAME TestClientSharedPathCommittedMidPush2440 client_integration_test.go:680: Retrieved narinfo from S3:2441 StorePath: /build/TestClientSharedPathCommittedMidPush325989011/001/store/67dcncl1xzra455nwc3qvazr3xkrnlnq-shared-dep2442 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2443 Compression: zstd2444 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822445 NarSize: 1362446 References: 2447 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2448=== NAME TestClientMultipleUploads24492026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)2450 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3815968272/001/store/sahr1i1pibb0li934dz804xspm3g3h7j-test-file-1.txt24512026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.41ms)2452=== NAME TestClientSharedPathCommittedMidPush24532026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures2454 client_integration_test.go:680: Retrieved narinfo from S3:2455 StorePath: /build/TestClientSharedPathCommittedMidPush325989011/001/store/3cg5mbdnrq4yqb174w5ybdij9v7qkkbn-top2456 URL: nar/0xkyqrgmb84lac6wjbmcpb75mq9fhxwn2h1jn1rmkjaqdsg264ma.nar.zst2457 Compression: zstd2458 NarHash: sha256:0xkyqrgmb84lac6wjbmcpb75mq9fhxwn2h1jn1rmkjaqdsg264ma2459 NarSize: 2242460 References: /build/TestClientSharedPathCommittedMidPush325989011/001/store/67dcncl1xzra455nwc3qvazr3xkrnlnq-shared-dep2461 CA: text:sha256:08d5699hr65znmfj9dxp9kjih9b44ladvpazw52kq23a6gjh5m2v24622026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.63ms)24632026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (2.15ms)24642026/10/01 09:33:47 goose: successfully migrated database to version: 202609231200002465--- PASS: TestClientSharedPathCommittedMidPush (0.74s)2466=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart24672026/10/01 09:33:47 INFO Received complete multipart upload request method=POST path=/24682026/10/01 09:33:47 OK 1_commit_pending_closure.sql (1.83ms)24692026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.16ms)24702026/10/01 09:33:47 OK 3_commit_push.sql (1.17ms)24712026/10/01 09:33:47 goose: up to current file version: 32472=== NAME TestClientIntegration2473 client_integration_test.go:286: Created store path: /build/TestClientIntegration1750523112/002/store/3xji66x4h6g4lfnfc54rjr75yq6jql5s-test-file.txt2474=== CONT TestIsValidCachePath/narinfo2475=== CONT TestIsValidCachePath/index.html2476=== CONT TestIsValidCachePath/nix-cache-info2477=== CONT TestIsValidCachePath/realisation2478=== CONT TestIsValidCachePath/log2479=== CONT TestIsValidCachePath/ls2480=== CONT TestIsValidCachePath/nar_uncompressed2481=== CONT TestIsValidCachePath/nar_bz22482=== CONT TestIsValidCachePath/nar_xz2483=== CONT TestIsValidCachePath/nar_zst2484=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2485=== CONT TestIsValidCachePath/traversal_parent2486=== CONT TestIsValidCachePath/empty2487=== CONT TestIsValidCachePath/random_path2488=== CONT TestIsValidCachePath/invalid_char_u2489=== CONT TestIsValidCachePath/invalid_char_e2490=== CONT TestIsValidCachePath/traversal_in_middle2491=== CONT TestIsValidCachePath/wrong_extension2492=== CONT TestIsValidCachePath/short_hash2493=== CONT TestIsValidCachePath/leading_slash2494--- PASS: TestIsValidCachePath (0.00s)2495 --- PASS: TestIsValidCachePath/narinfo (0.00s)2496 --- PASS: TestIsValidCachePath/index.html (0.00s)2497 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2498 --- PASS: TestIsValidCachePath/realisation (0.00s)2499 --- PASS: TestIsValidCachePath/log (0.00s)2500 --- PASS: TestIsValidCachePath/ls (0.00s)2501 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2502 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2503 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2504 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2505 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2506 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2507 --- PASS: TestIsValidCachePath/empty (0.00s)2508 --- PASS: TestIsValidCachePath/random_path (0.00s)2509 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2510 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2511 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2512 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2513 --- PASS: TestIsValidCachePath/short_hash (0.00s)2514 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2515=== CONT TestParseSingleRange/none2516=== CONT TestParseSingleRange/open-ended2517=== CONT TestParseSingleRange/start_far_past_EOF2518=== CONT TestParseSingleRange/start_past_EOF2519=== CONT TestParseSingleRange/single_byte2520=== CONT TestParseSingleRange/suffix_exceeds_size2521=== CONT TestParseSingleRange/suffix2522=== CONT TestParseSingleRange/end_clamped_to_size2523=== CONT TestParseSingleRange/malformed_both_empty2524=== CONT TestParseSingleRange/closed2525=== CONT TestParseSingleRange/malformed_end_before_start2526=== CONT TestParseSingleRange/multi-range_ignored2527=== CONT TestParseSingleRange/malformed_no_dash2528=== CONT TestParseSingleRange/unknown_unit2529--- PASS: TestParseSingleRange (0.00s)2530 --- PASS: TestParseSingleRange/none (0.00s)2531 --- PASS: TestParseSingleRange/open-ended (0.00s)2532 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2533 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2534 --- PASS: TestParseSingleRange/single_byte (0.00s)2535 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2536 --- PASS: TestParseSingleRange/suffix (0.00s)2537 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2538 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2539 --- PASS: TestParseSingleRange/closed (0.00s)2540 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2541 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2542 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2543 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2544=== CONT TestServerTLSConfig/no_client_CA2545=== CONT TestServerTLSConfig/not_a_PEM_file2546=== CONT TestServerTLSConfig/missing_CA_file2547--- PASS: TestServerTLSConfig (0.00s)2548 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2549 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2550 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2551=== CONT TestPush_RejectsBadRequests/no_objects25522026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes2553=== CONT TestPush_RejectsBadRequests/no_roots25542026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes2555=== CONT TestPush_RejectsBadRequests/root_not_in_objects25562026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes2557=== CONT TestPush_RejectsBadRequests/bad_root25582026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes2559=== CONT TestResolveDBConnectionString/flag_wins2560=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2561=== CONT TestResolveDBConnectionString/nothing_configured2562=== CONT TestResolveDBConnectionString/missing_file_is_an_error2563--- PASS: TestPush_RejectsBadRequests (0.86s)2564 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2565 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2566 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2567 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2568=== CONT TestResolveDBConnectionString/file_when_flag_empty2569=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2570--- PASS: TestResolveDBConnectionString (0.00s)2571 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2572 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2573 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2574 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2575 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2576=== NAME TestClientMultipleUploads2577 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3815968272/001/store/94zmpl75m8xn045pqq8mi3wb3ish8hx7-test-file-2.txt25782026/10/01 09:33:47 INFO Aborted multipart uploads count=025792026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period2580--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.46s)2581=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2582=== CONT TestClientErrorHandling/InvalidStorePath25832026/10/01 09:33: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=025842026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes25852026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes25862026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures25872026/10/01 09:33:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25882026/10/01 09:33:47 INFO Uploading 044f433vlb2y9b4lyknwxm8brvjk8l95-unpinned-file.txt (128B)25892026/10/01 09:33:47 INFO Vacuumed table table=pending_closures25902026/10/01 09:33:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25912026/10/01 09:33:47 INFO Uploading ydy1y3flvd533an5mp146fxnw8cda97d-test-script (136B)25922026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"25932026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign25942026/10/01 09:33:47 INFO Received uploads request method=POST path=/api/pending_closures25952026/10/01 09:33:47 INFO Vacuumed table table=pending_objects25962026/10/01 09:33:47 INFO Signed narinfos id=2 count=125972026/10/01 09:33:47 WARN Failed to register uploaded object key=044f433vlb2y9b4lyknwxm8brvjk8l95.ls error="server returned 404: 404 page not found\n"25982026/10/01 09:33:47 INFO Uploading 1 narinfos25992026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads26002026/10/01 09:33:47 INFO Vacuumed table table=closures26012026/10/01 09:33:47 WARN Failed to register uploaded object key=ydy1y3flvd533an5mp146fxnw8cda97d.ls error="server returned 404: 404 page not found\n"26022026/10/01 09:33:47 WARN Failed to register uploaded object key=log/1l4x83929npwzzrq9nb11azr86kwzywf-test-script.drv error="server returned 404: 404 page not found\n"26032026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26042026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"26052026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/2/complete26062026/10/01 09:33:47 WARN Failed to register uploaded object key=044f433vlb2y9b4lyknwxm8brvjk8l95.narinfo error="server returned 404: 404 page not found\n"26072026/10/01 09:33:47 INFO Signed narinfos id=1 count=126082026/10/01 09:33:47 INFO Uploading 1 narinfos2609--- PASS: TestGetExistingObjectsLocksRows (0.51s)2610=== CONT TestClientErrorHandling/ServerNotAvailable26112026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete26122026/10/01 09:33:47 WARN Failed to register uploaded object key=ydy1y3flvd533an5mp146fxnw8cda97d.narinfo error="server returned 404: 404 page not found\n"26132026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes26142026/10/01 09:33:47 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)26152026/10/01 09:33:47 INFO Uploading fq7gr9r3zwxff17xqzc0382vis2vy5c7-shared-dep (136B)26162026/10/01 09:33:47 INFO Uploading 7zbhjagzw67rzgjyrri71m0fi35rlvnx-a (216B)26172026/10/01 09:33:47 INFO Upload complete. (86ms)26182026/10/01 09:33:47 INFO Vacuumed table table=objects26192026/10/01 09:33:47 INFO Upload complete. (97ms)2620=== NAME TestClientWithDependencies26212026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/0dmmmy4fmm9g44kbdmjgy2g6mip497991a5yryiz8c8bkpjgksjp.nar.zst error="server returned 404: 404 page not found\n"2622 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3620199767/001/store) requires matching store prefix26232026/10/01 09:33:47 WARN Failed to register uploaded object key=7x4z2rms19028hwarrfg8bnh9wwg3csi.ls error="server returned 404: 404 page not found\n"2624--- PASS: TestSweepRechecksPendingAfterLocking (0.55s)26252026/10/01 09:33:47 WARN Failed to register uploaded object key=7zbhjagzw67rzgjyrri71m0fi35rlvnx.ls error="server returned 404: 404 page not found\n"2626=== CONT TestClientErrorHandling/InvalidAuthToken26272026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"26282026/10/01 09:33:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26292026/10/01 09:33:47 INFO Uploading 3xji66x4h6g4lfnfc54rjr75yq6jql5s-test-file.txt (152B)26302026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign26312026/10/01 09:33:47 WARN Failed to register uploaded object key=fq7gr9r3zwxff17xqzc0382vis2vy5c7.ls error="server returned 404: 404 page not found\n"26322026/10/01 09:33:47 INFO Signed narinfos id=1 count=226332026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign26342026/10/01 09:33:47 INFO Signed narinfos id=2 count=22635--- PASS: TestClientWithDependencies (0.78s)2636=== CONT TestCacheConfigHandler/full_config,_no_issuer26372026/10/01 09:33:47 INFO Uploading 4 narinfos2638=== CONT TestCacheConfigHandler/no_signing_keys2639=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2640=== CONT TestCacheConfigHandler/no_cache_url_configured2641--- PASS: TestCacheConfigHandler (0.00s)2642 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2643 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2644 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2645 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)26462026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"26472026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes26482026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26492026/10/01 09:33:47 WARN Failed to register uploaded object key=3xji66x4h6g4lfnfc54rjr75yq6jql5s.ls error="server returned 404: 404 page not found\n"26502026/10/01 09:33:47 INFO Signed narinfos id=1 count=126512026/10/01 09:33:47 INFO Uploading 1 narinfos26522026/10/01 09:33:47 WARN Failed to register uploaded object key=fq7gr9r3zwxff17xqzc0382vis2vy5c7.narinfo error="server returned 404: 404 page not found\n"26532026/10/01 09:33:47 WARN Failed to register uploaded object key=7zbhjagzw67rzgjyrri71m0fi35rlvnx.narinfo error="server returned 404: 404 page not found\n"26542026/10/01 09:33:47 WARN Failed to register uploaded object key=7x4z2rms19028hwarrfg8bnh9wwg3csi.narinfo error="server returned 404: 404 page not found\n"26552026/10/01 09:33:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete26562026/10/01 09:33:47 WARN Failed to register uploaded object key=fq7gr9r3zwxff17xqzc0382vis2vy5c7.narinfo error="server returned 404: 404 page not found\n"26572026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete26582026/10/01 09:33:47 WARN Failed to register uploaded object key=3xji66x4h6g4lfnfc54rjr75yq6jql5s.narinfo error="server returned 404: 404 page not found\n"26592026/10/01 09:33:47 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)26602026/10/01 09:33:47 INFO Uploading sahr1i1pibb0li934dz804xspm3g3h7j-test-file-1.txt (160B)26612026/10/01 09:33:47 INFO Uploading xg410fi2mhkv891108b4cbx5sfmimiks-test-file-0.txt (160B)26622026/10/01 09:33:47 INFO Uploading 94zmpl75m8xn045pqq8mi3wb3ish8hx7-test-file-2.txt (160B)26632026/10/01 09:33:47 INFO Completed upload id=126642026/10/01 09:33:47 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete26652026/10/01 09:33:47 WARN Failed to register uploaded object key=xg410fi2mhkv891108b4cbx5sfmimiks.ls error="server returned 404: 404 page not found\n"26662026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"26672026/10/01 09:33:47 INFO Upload complete. (77ms)26682026/10/01 09:33:47 WARN Failed to register uploaded object key=sahr1i1pibb0li934dz804xspm3g3h7j.ls error="server returned 404: 404 page not found\n"26692026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"26702026/10/01 09:33:47 INFO Completed upload id=226712026/10/01 09:33:47 INFO Upload complete. (101ms)26722026/10/01 09:33:47 WARN Failed to register uploaded object key=94zmpl75m8xn045pqq8mi3wb3ish8hx7.ls error="server returned 404: 404 page not found\n"26732026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"26742026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26752026/10/01 09:33:47 INFO Signed narinfos id=1 count=326762026/10/01 09:33:47 INFO Uploading 3 narinfos2677=== NAME TestClientFallsBackToClosures2678 client_pushes_test.go:112: Retrieved narinfo from S3:2679 StorePath: /build/TestClientFallsBackToClosures68605336/001/store/fq7gr9r3zwxff17xqzc0382vis2vy5c7-shared-dep2680 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2681 Compression: zstd2682 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822683 NarSize: 1362684 References: 2685 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2686--- PASS: TestCacheStatsHandler (0.54s)2687=== NAME TestClientFallsBackToClosures2688 client_pushes_test.go:112: Retrieved narinfo from S3:2689 StorePath: /build/TestClientFallsBackToClosures68605336/001/store/7zbhjagzw67rzgjyrri71m0fi35rlvnx-a2690 URL: nar/0dmmmy4fmm9g44kbdmjgy2g6mip497991a5yryiz8c8bkpjgksjp.nar.zst2691 Compression: zstd2692 NarHash: sha256:0dmmmy4fmm9g44kbdmjgy2g6mip497991a5yryiz8c8bkpjgksjp2693 NarSize: 2162694 References: /build/TestClientFallsBackToClosures68605336/001/store/fq7gr9r3zwxff17xqzc0382vis2vy5c7-shared-dep2695 CA: text:sha256:01l403m7kg0cc4wxlqgrkv09gmc45yp3rf95zlcbgjkgkka2clx826962026/10/01 09:33:47 WARN Failed to register uploaded object key=94zmpl75m8xn045pqq8mi3wb3ish8hx7.narinfo error="server returned 404: 404 page not found\n"26972026/10/01 09:33:47 WARN Failed to register uploaded object key=sahr1i1pibb0li934dz804xspm3g3h7j.narinfo error="server returned 404: 404 page not found\n"26982026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete26992026/10/01 09:33:47 WARN Failed to register uploaded object key=xg410fi2mhkv891108b4cbx5sfmimiks.narinfo error="server returned 404: 404 page not found\n"2700 client_pushes_test.go:112: Retrieved narinfo from S3:2701 StorePath: /build/TestClientFallsBackToClosures68605336/001/store/7x4z2rms19028hwarrfg8bnh9wwg3csi-b2702 URL: nar/0dmmmy4fmm9g44kbdmjgy2g6mip497991a5yryiz8c8bkpjgksjp.nar.zst2703 Compression: zstd2704 NarHash: sha256:0dmmmy4fmm9g44kbdmjgy2g6mip497991a5yryiz8c8bkpjgksjp2705 NarSize: 2162706 References: /build/TestClientFallsBackToClosures68605336/001/store/fq7gr9r3zwxff17xqzc0382vis2vy5c7-shared-dep2707 CA: text:sha256:01l403m7kg0cc4wxlqgrkv09gmc45yp3rf95zlcbgjkgkka2clx827082026/10/01 09:33:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures27092026/10/01 09:33:47 INFO Garbage collection started2710--- PASS: TestClientFallsBackToClosures (0.74s)2711=== RUN TestService_RequireScope_OIDC/builder_may_write2712=== PAUSE TestService_RequireScope_OIDC/builder_may_write2713=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2714=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2715=== RUN TestService_RequireScope_OIDC/ops_may_admin2716=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2717=== RUN TestService_RequireScope_OIDC/ops_may_not_write2718=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2719=== RUN TestService_RequireScope_OIDC/reader_may_not_write2720=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2721=== RUN TestService_RequireScope_OIDC/static_token_may_admin2722=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2723=== RUN TestService_RequireScope_OIDC/static_token_may_write2724=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2725=== RUN TestService_RequireScope_OIDC/reader_may_read2726=== PAUSE TestService_RequireScope_OIDC/reader_may_read2727=== RUN TestService_RequireScope_OIDC/writer_implies_read2728=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2729=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2730=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2731=== CONT TestService_RequireScope_OIDC/builder_may_write2732=== CONT TestService_RequireScope_OIDC/static_token_may_admin2733=== CONT TestService_RequireScope_OIDC/reader_may_read2734=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2735=== CONT TestService_RequireScope_OIDC/static_token_may_write2736=== CONT TestService_RequireScope_OIDC/writer_implies_read2737=== CONT TestService_RequireScope_OIDC/ops_may_admin2738=== CONT TestService_RequireScope_OIDC/reader_may_not_write2739=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2740=== CONT TestService_RequireScope_OIDC/ops_may_not_write2741--- PASS: TestService_RequireScope_OIDC (0.56s)2742 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2743 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2744 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2745 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2746 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2747 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2748 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2749 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2750 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2751 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)27522026/10/01 09:33:47 INFO Upload complete. (82ms)2753=== NAME TestClientMultipleUploads27542026/10/01 09:33:47 INFO Received push request method=POST path=/api/pushes2755 client_integration_test.go:369: Uploaded 3 paths in 114.814581ms27562026/10/01 09:33:47 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)27572026/10/01 09:33:47 INFO Uploading h5anpqw2h58cd69ihd51rx71q0xwrkd9-shared-dep (136B)27582026/10/01 09:33:47 INFO Uploading s84yyc9mgnqjcbqcgkqpfrzpvlfb0qzm-a (216B)27592026-10-01 09:33:47.879 UTC [1619] ERROR: relation "goose_db_version" does not exist at character 3627602026-10-01 09:33:47.879 UTC [1619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27612026/10/01 09:33:47 INFO Aborted multipart uploads count=02762--- PASS: TestClientMultipleUploads (0.76s)27632026/10/01 09:33:47 WARN Failed to register uploaded object key=h6xvbc4kbasdbxzfs9lwzim4klwicbyk.ls error="server returned 404: 404 page not found\n"27642026/10/01 09:33:47 WARN Failed to register uploaded object key=h5anpqw2h58cd69ihd51rx71q0xwrkd9.ls error="server returned 404: 404 page not found\n"27652026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"27662026/10/01 09:33:47 WARN Failed to register uploaded object key=nar/0zjgg42f75v6q9s8ddxqg41a3shmjlh3cxq0m2xchw5bpqmhkl2k.nar.zst error="server returned 404: 404 page not found\n"27672026/10/01 09:33:47 WARN Failed to register uploaded object key=s84yyc9mgnqjcbqcgkqpfrzpvlfb0qzm.ls error="server returned 404: 404 page not found\n"27682026/10/01 09:33:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27692026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period27702026/10/01 09:33:47 INFO Signed narinfos id=1 count=327712026/10/01 09:33:47 INFO Uploading 3 narinfos27722026/10/01 09:33:47 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/present27732026/10/01 09:33:47 INFO All 1 paths already cached2774=== NAME TestClientIntegration27752026/10/01 09:33:47 WARN Failed to register uploaded object key=h6xvbc4kbasdbxzfs9lwzim4klwicbyk.narinfo error="server returned 404: 404 page not found\n"2776 client_integration_test.go:312: Retrieved narinfo from S3:2777 StorePath: /build/TestClientIntegration1750523112/002/store/3xji66x4h6g4lfnfc54rjr75yq6jql5s-test-file.txt2778 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2779 Compression: zstd2780 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk127812026/10/01 09:33:47 WARN Failed to register uploaded object key=s84yyc9mgnqjcbqcgkqpfrzpvlfb0qzm.narinfo error="server returned 404: 404 page not found\n"2782 NarSize: 1522783 References: 2784 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk127852026/10/01 09:33:47 INFO Received complete push request method=POST path=/api/pushes/1/complete27862026/10/01 09:33:47 WARN Failed to register uploaded object key=h5anpqw2h58cd69ihd51rx71q0xwrkd9.narinfo error="server returned 404: 404 page not found\n"2787 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2788 client_integration_test.go:313: Decompressed .ls content (64 bytes):2789 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2790 client_integration_test.go:316: Testing garbage collection...27912026-10-01 09:33:47.893 UTC [1652] ERROR: relation "goose_db_version" does not exist at character 3627922026-10-01 09:33:47.893 UTC [1652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27932026/10/01 09:33:47 OK 20241026095416_initial_model.sql (8.85ms)27942026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)27952026/10/01 09:33:47 INFO Upload complete. (82ms)27962026/10/01 09:33:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=027972026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.86ms)2798=== NAME TestClientPushesUseOnePush2799 client_pushes_test.go:97: Retrieved narinfo from S3:2800 StorePath: /build/TestClientPushesUseOnePush2516387021/001/store/h5anpqw2h58cd69ihd51rx71q0xwrkd9-shared-dep2801 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2802 Compression: zstd2803 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822804 NarSize: 1362805 References: 2806 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2807--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.85s)2808=== NAME TestClientPushesUseOnePush2809 client_pushes_test.go:97: Retrieved narinfo from S3:2810 StorePath: /build/TestClientPushesUseOnePush2516387021/001/store/s84yyc9mgnqjcbqcgkqpfrzpvlfb0qzm-a2811 URL: nar/0zjgg42f75v6q9s8ddxqg41a3shmjlh3cxq0m2xchw5bpqmhkl2k.nar.zst2812 Compression: zstd2813 NarHash: sha256:0zjgg42f75v6q9s8ddxqg41a3shmjlh3cxq0m2xchw5bpqmhkl2k28142026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)2815 NarSize: 2162816 References: /build/TestClientPushesUseOnePush2516387021/001/store/h5anpqw2h58cd69ihd51rx71q0xwrkd9-shared-dep2817 CA: text:sha256:19cfv8qc76238ga0k3bxawlhyrvidrdf6432dgmx1hhkxfkdq0yl28182026/10/01 09:33:47 INFO Vacuumed table table=pending_closures28192026-10-01 09:33:47.905 UTC [1655] ERROR: relation "goose_db_version" does not exist at character 3628202026-10-01 09:33:47.905 UTC [1655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2821 client_pushes_test.go:97: Retrieved narinfo from S3:2822 StorePath: /build/TestClientPushesUseOnePush2516387021/001/store/h6xvbc4kbasdbxzfs9lwzim4klwicbyk-b2823 URL: nar/0zjgg42f75v6q9s8ddxqg41a3shmjlh3cxq0m2xchw5bpqmhkl2k.nar.zst2824 Compression: zstd2825 NarHash: sha256:0zjgg42f75v6q9s8ddxqg41a3shmjlh3cxq0m2xchw5bpqmhkl2k2826 NarSize: 2162827 References: /build/TestClientPushesUseOnePush2516387021/001/store/h5anpqw2h58cd69ihd51rx71q0xwrkd9-shared-dep2828 CA: text:sha256:19cfv8qc76238ga0k3bxawlhyrvidrdf6432dgmx1hhkxfkdq0yl28292026/10/01 09:33:47 INFO Vacuumed table table=pending_objects28302026/10/01 09:33:47 OK 20260905000000_add_claims.sql (3.55ms)28312026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads2832--- PASS: TestService_ReadScope_PublicByDefault (0.51s)28332026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.93ms)28342026/10/01 09:33:47 OK 20241026095416_initial_model.sql (9.26ms)28352026/10/01 09:33:47 INFO Vacuumed table table=closures28362026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.6ms)28372026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000028382026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)28392026/10/01 09:33:47 INFO Vacuumed table table=objects28402026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.07ms)2841--- PASS: TestClientPushesUseOnePush (0.76s)28422026/10/01 09:33:47 OK 20251218171726_add_pins.sql (2.57ms)28432026/10/01 09:33:47 OK 2_object_stats_trigger.sql (1.39ms)28442026/10/01 09:33:47 OK 3_commit_push.sql (9.09ms)28452026/10/01 09:33:47 goose: up to current file version: 328462026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (11.13ms)28472026/10/01 09:33:47 OK 20241026095416_initial_model.sql (12.36ms)28482026/10/01 09:33:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures28492026/10/01 09:33:47 INFO Garbage collection started28502026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)28512026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.64ms)28522026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.83ms)28532026/10/01 09:33:47 OK 20251218171726_add_pins.sql (3.81ms)28542026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.6ms)28552026/10/01 09:33:47 goose: successfully migrated database to version: 202609231200002856--- PASS: TestService_ReadAuthMiddleware (0.52s)28572026/10/01 09:33:47 OK 1_commit_pending_closure.sql (2.38ms)28582026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)28592026/10/01 09:33:47 INFO Aborted multipart uploads count=028602026/10/01 09:33:47 OK 2_object_stats_trigger.sql (901.73µs)28612026/10/01 09:33:47 OK 3_commit_push.sql (554.12µs)28622026/10/01 09:33:47 goose: up to current file version: 328632026/10/01 09:33:47 OK 20260905000000_add_claims.sql (2.28ms)28642026/10/01 09:33:47 WARN Force mode enabled - objects will be deleted immediately without grace period28652026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.47ms)28662026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.62ms)28672026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000028682026/10/01 09:33:47 OK 1_commit_pending_closure.sql (1.69ms)28692026-10-01 09:33:47.942 UTC [1691] ERROR: relation "goose_db_version" does not exist at character 3628702026-10-01 09:33:47.942 UTC [1691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28712026/10/01 09:33:47 OK 2_object_stats_trigger.sql (651.88µs)28722026/10/01 09:33:47 OK 3_commit_push.sql (626.98µs)28732026/10/01 09:33:47 goose: up to current file version: 328742026/10/01 09:33:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=028752026/10/01 09:33:47 OK 20241026095416_initial_model.sql (6.78ms)28762026/10/01 09:33:47 INFO Vacuumed table table=pending_closures28772026/10/01 09:33:47 OK 20251210153512_drop_unused_gin_index.sql (887.52µs)28782026/10/01 09:33:47 INFO Vacuumed table table=pending_objects28792026/10/01 09:33:47 INFO Vacuumed table table=multipart_uploads28802026/10/01 09:33:47 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"28812026/10/01 09:33:47 OK 20251218171726_add_pins.sql (1.97ms)28822026/10/01 09:33:47 WARN mTLS auth: bound subjects configured but subject DN unavailable28832026/10/01 09:33:47 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2884--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.47s)28852026/10/01 09:33:47 INFO Vacuumed table table=closures28862026/10/01 09:33:47 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)28872026/10/01 09:33:47 INFO Vacuumed table table=objects28882026/10/01 09:33:47 OK 20260905000000_add_claims.sql (1.91ms)28892026/10/01 09:33:47 OK 20260920000000_drop_claims.sql (1.43ms)28902026/10/01 09:33:47 OK 20260923120000_add_pushes.sql (1.07ms)28912026/10/01 09:33:47 goose: successfully migrated database to version: 2026092312000028922026/10/01 09:33:47 OK 1_commit_pending_closure.sql (1.27ms)28932026/10/01 09:33:47 OK 2_object_stats_trigger.sql (846.75µs)28942026/10/01 09:33:47 OK 3_commit_push.sql (704.38µs)28952026/10/01 09:33:47 goose: up to current file version: 32896=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2897=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2898=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2899=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2900=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2901=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2902=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2903=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2904=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2905=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2906=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured29072026/10/01 09:33:47 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]2908=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2909=== NAME TestClientCADerivations2910 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3584647474/001/store/rm6f2ca5yxdqh84836ix5c0mhn2ybbr9-ca-test29112026/10/01 09:33:47 WARN Authentication failed token_preview=eyJhbGciOi...ifGhYoqC9w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2912--- PASS: TestService_AuthMiddleware_OIDC (0.53s)2913 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2914 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2915 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2916 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)29172026/10/01 09:33:47 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.423539ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2918--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.39s)2919=== NAME TestClientCADerivations2920 client_ca_test.go:139: Found 1 dependencies (including self)29212026/10/01 09:33:48 INFO Received uploads request method=POST path=/api/pending_closures29222026/10/01 09:33:48 INFO Aborted multipart uploads count=029232026/10/01 09:33:48 WARN Force mode enabled - objects will be deleted immediately without grace period29242026/10/01 09:33:48 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029252026/10/01 09:33:48 INFO Received uploads request method=POST path=/api/pending_closures29262026/10/01 09:33:48 INFO Vacuumed table table=pending_closures29272026/10/01 09:33:48 INFO Vacuumed table table=pending_objects29282026/10/01 09:33:48 INFO Vacuumed table table=multipart_uploads29292026/10/01 09:33:48 INFO Vacuumed table table=closures29302026/10/01 09:33:48 INFO Vacuumed table table=objects29312026/10/01 09:33:48 INFO Aborted multipart uploads count=029322026/10/01 09:33:48 WARN Force mode enabled - objects will be deleted immediately without grace period29332026/10/01 09:33:48 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=029342026/10/01 09:33:48 INFO Vacuumed table table=pending_closures29352026/10/01 09:33:48 INFO Vacuumed table table=pending_objects29362026/10/01 09:33:48 INFO Vacuumed table table=multipart_uploads29372026/10/01 09:33:48 INFO Vacuumed table table=closures29382026/10/01 09:33:48 INFO Vacuumed table table=objects2939--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2940 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)2941 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)29422026/10/01 09:33:48 INFO Received push request method=POST path=/api/pushes29432026/10/01 09:33:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29442026/10/01 09:33:48 INFO Uploading rm6f2ca5yxdqh84836ix5c0mhn2ybbr9-ca-test (144B)29452026/10/01 09:33:48 WARN Failed to register uploaded object key=rm6f2ca5yxdqh84836ix5c0mhn2ybbr9.ls error="server returned 404: 404 page not found\n"29462026/10/01 09:33:48 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"29472026/10/01 09:33:48 WARN Failed to register uploaded object key=log/m2ncfxp591qd8pakqybxaz94ypf8qv9v-ca-test.drv error="server returned 404: 404 page not found\n"29482026/10/01 09:33:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29492026/10/01 09:33:48 INFO Signed narinfos id=1 count=129502026/10/01 09:33:48 INFO Uploading 1 narinfos29512026/10/01 09:33:48 INFO Received complete push request method=POST path=/api/pushes/1/complete29522026/10/01 09:33:48 WARN Failed to register uploaded object key=rm6f2ca5yxdqh84836ix5c0mhn2ybbr9.narinfo error="server returned 404: 404 page not found\n"29532026/10/01 09:33:48 INFO Upload complete. (88ms)2954=== NAME TestClientCADerivations2955 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3584647474/001/store/rm6f2ca5yxdqh84836ix5c0mhn2ybbr9-ca-test2956 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2957 Compression: zstd2958 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2959 NarSize: 1442960 References: 2961 Deriver: /build/TestClientCADerivations3584647474/001/store/m2ncfxp591qd8pakqybxaz94ypf8qv9v-ca-test.drv2962 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2963 client_ca_test.go:185: Checking for realisation files in S3...2964 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2965 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache29662026/10/01 09:33:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29672026/10/01 09:33:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.0978ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2968 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2969 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2970 error: binary cache 's3://bucket74?endpoint=http://localhost:44665&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3584647474/001/store'2971 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12972--- PASS: TestUploadHandlersRejectOversizedBody (0.20s)2973 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2974 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2975 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.71s)29762026/10/01 09:33:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2977--- PASS: TestPushWaitsForSweepHoldingRow (1.12s)2978--- PASS: TestClientCADerivations (1.00s)2979=== NAME TestOrphanedObjectsGCStressTest2980 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2981 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion29822026/10/01 09:33:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=797.9027ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2983 orphaned_objects_gc_test.go:509: Stress test completed successfully:2984 orphaned_objects_gc_test.go:510: - Active objects preserved: 202985 orphaned_objects_gc_test.go:511: - Objects deleted: 2102986 orphaned_objects_gc_test.go:512: - Total GC'd: 2102987--- PASS: TestOrphanedObjectsGCStressTest (2.61s)29882026/10/01 09:33:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.538935059s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29892026/10/01 09:33:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=029902026/10/01 09:33:49 INFO Received create pin request method=POST path=/api/pins/myapp29912026/10/01 09:33:49 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2123900093/001/store/2y1wcp0yjp2plvamrm5l7964sh2kl4r2-pinned-file.txt narinfo_key=2y1wcp0yjp2plvamrm5l7964sh2kl4r2.narinfo29922026/10/01 09:33:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures29932026/10/01 09:33:49 INFO Garbage collection started29942026/10/01 09:33:49 INFO Aborted multipart uploads count=029952026/10/01 09:33:49 WARN Force mode enabled - objects will be deleted immediately without grace period29962026/10/01 09:33:49 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=029972026/10/01 09:33:49 INFO Vacuumed table table=pending_closures29982026/10/01 09:33:49 INFO Vacuumed table table=pending_objects29992026/10/01 09:33:49 INFO Vacuumed table table=multipart_uploads30002026/10/01 09:33:49 INFO Vacuumed table table=closures30012026/10/01 09:33:49 INFO Vacuumed table table=objects30022026/10/01 09:33:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03003=== NAME TestClientIntegration3004 client_integration_test.go:323: Objects in database after GC:3005 client_integration_test.go:323: Successfully deleted all objects with GC --force3006--- PASS: TestClientIntegration (2.75s)30072026/10/01 09:33:50 WARN Rate limiter enabled after throttle name=s3-test rate=530082026/10/01 09:33:50 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3009=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3010 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103011 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003012--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.32s)30132026/10/01 09:33:50 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-config30142026/10/01 09:33:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.744108ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30152026/10/01 09:33:51 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.904712ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30162026/10/01 09:33:51 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=839.523403ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3017=== NAME TestPinProtectsFromGC3018 client_integration_test.go:840: Pin successfully protected closure from garbage collection3019--- PASS: TestPinProtectsFromGC (4.99s)30202026/10/01 09:33:52 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.659237374s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30212026/10/01 09:33:54 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"30222026/10/01 09:33:54 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-config30232026/10/01 09:33:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.242373ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30242026/10/01 09:33:54 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.571517ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30252026/10/01 09:33:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.86491ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30262026/10/01 09:33:55 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.733985181s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30272026/10/01 09:33:57 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_closures30282026/10/01 09:33:57 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.299464ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30292026/10/01 09:33:57 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.888012ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30302026/10/01 09:33:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=861.064089ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30312026/10/01 09:33:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.503682477s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3032--- PASS: TestClientErrorHandling (0.00s)3033 --- PASS: TestClientErrorHandling/InvalidStorePath (0.35s)3034 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.56s)3035 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.73s)3036PASS30372026-10-01 09:34:00.856 UTC [127] LOG: received smart shutdown request30382026-10-01 09:34:00.863 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 130392026-10-01 09:34:00.868 UTC [132] LOG: shutting down30402026-10-01 09:34:00.869 UTC [132] LOG: checkpoint starting: shutdown immediate30412026-10-01 09:34:02.468 UTC [132] LOG: checkpoint complete: wrote 10356 buffers (63.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.258 s, sync=1.286 s, total=1.599 s; sync files=27976, longest=0.003 s, average=0.001 s; distance=387405 kB, estimate=387405 kB; lsn=0/191B91A8, redo lsn=0/191B91A830422026-10-01 09:34:02.546 UTC [127] LOG: database system is shut down3043Running OIDC tests...3044=== RUN TestAudienceForIssuer3045=== PAUSE TestAudienceForIssuer3046=== RUN TestGlobMatch3047=== PAUSE TestGlobMatch3048=== RUN TestValidateToken_ValidToken3049=== PAUSE TestValidateToken_ValidToken3050=== RUN TestValidateToken_WrongAudience3051=== PAUSE TestValidateToken_WrongAudience3052=== RUN TestValidateToken_Expired3053=== PAUSE TestValidateToken_Expired3054=== RUN TestValidateToken_BoundClaimsMismatch3055=== PAUSE TestValidateToken_BoundClaimsMismatch3056=== RUN TestValidateToken_BoundSubjectMismatch3057=== PAUSE TestValidateToken_BoundSubjectMismatch3058=== RUN TestValidateToken_MultipleProviders3059=== PAUSE TestValidateToken_MultipleProviders3060=== RUN TestValidateToken_NoMatchingProvider3061=== PAUSE TestValidateToken_NoMatchingProvider3062=== RUN TestValidateToken_KubernetesServiceAccount3063=== PAUSE TestValidateToken_KubernetesServiceAccount3064=== RUN TestNewValidator_KubernetesRequiresCA3065=== PAUSE TestNewValidator_KubernetesRequiresCA3066=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3067=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3068=== RUN TestPins_ReservedForMatchingRule3069=== PAUSE TestPins_ReservedForMatchingRule3070=== RUN TestPins_TopLevelShorthand3071=== PAUSE TestPins_TopLevelShorthand3072=== RUN TestPins_ConfigValidation3073=== PAUSE TestPins_ConfigValidation3074=== RUN TestScopes_LegacyProviderDefaultsToWrite3075=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3076=== RUN TestScopes_Rules3077=== PAUSE TestScopes_Rules3078=== RUN TestScopes_ConfigValidation3079=== PAUSE TestScopes_ConfigValidation3080=== CONT TestAudienceForIssuer3081=== CONT TestValidateToken_KubernetesServiceAccount3082--- PASS: TestAudienceForIssuer (0.00s)3083=== CONT TestValidateToken_Expired3084=== CONT TestValidateToken_WrongAudience3085=== CONT TestValidateToken_ValidToken3086=== CONT TestGlobMatch3087=== CONT TestValidateToken_MultipleProviders3088=== CONT TestValidateToken_NoMatchingProvider3089=== CONT TestValidateToken_BoundSubjectMismatch3090=== CONT TestScopes_Rules3091=== CONT TestScopes_ConfigValidation3092=== CONT TestScopes_LegacyProviderDefaultsToWrite3093=== CONT TestPins_ReservedForMatchingRule3094--- PASS: TestScopes_ConfigValidation (0.00s)3095=== CONT TestPins_ConfigValidation3096=== CONT TestPins_TopLevelShorthand3097=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3098=== CONT TestNewValidator_KubernetesRequiresCA3099=== CONT TestValidateToken_BoundClaimsMismatch3100=== RUN TestGlobMatch/foo_foo3101=== PAUSE TestGlobMatch/foo_foo3102--- PASS: TestPins_ConfigValidation (0.00s)3103=== RUN TestGlobMatch/foo_bar3104=== PAUSE TestGlobMatch/foo_bar3105=== RUN TestGlobMatch/*_3106=== PAUSE TestGlobMatch/*_3107=== RUN TestGlobMatch/*_anything3108=== PAUSE TestGlobMatch/*_anything3109=== RUN TestGlobMatch/foo*_foo3110=== PAUSE TestGlobMatch/foo*_foo3111=== RUN TestGlobMatch/foo*_foobar3112=== PAUSE TestGlobMatch/foo*_foobar3113=== RUN TestGlobMatch/foo*_bar3114=== PAUSE TestGlobMatch/foo*_bar3115=== RUN TestGlobMatch/*bar_bar3116=== PAUSE TestGlobMatch/*bar_bar3117=== RUN TestGlobMatch/*bar_foobar3118=== PAUSE TestGlobMatch/*bar_foobar3119=== RUN TestGlobMatch/*bar_foo3120=== PAUSE TestGlobMatch/*bar_foo3121=== RUN TestGlobMatch/foo*bar_foobar3122=== PAUSE TestGlobMatch/foo*bar_foobar3123=== RUN TestGlobMatch/foo*bar_foo123bar3124=== PAUSE TestGlobMatch/foo*bar_foo123bar3125=== RUN TestGlobMatch/foo*bar_foobarbaz3126=== PAUSE TestGlobMatch/foo*bar_foobarbaz3127=== RUN TestGlobMatch/*/*_foo/bar3128=== PAUSE TestGlobMatch/*/*_foo/bar3129=== RUN TestGlobMatch/*/*_foo3130=== PAUSE TestGlobMatch/*/*_foo3131=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3132=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3133=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03134=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03135=== RUN TestGlobMatch/refs/*/main_refs/heads/main3136=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3137=== RUN TestGlobMatch/fo?_foo3138=== PAUSE TestGlobMatch/fo?_foo3139=== RUN TestGlobMatch/fo?_fo3140=== PAUSE TestGlobMatch/fo?_fo3141=== RUN TestGlobMatch/fo?_fooo3142=== PAUSE TestGlobMatch/fo?_fooo3143=== RUN TestGlobMatch/?oo_foo3144=== PAUSE TestGlobMatch/?oo_foo3145=== RUN TestGlobMatch/?oo_boo3146=== PAUSE TestGlobMatch/?oo_boo3147=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3148=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3149=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3150=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3151=== CONT TestGlobMatch/foo_foo3152=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3153=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3154=== CONT TestGlobMatch/foo*bar_foo123bar3155=== CONT TestGlobMatch/refs/*/main_refs/heads/main3156=== CONT TestGlobMatch/fo?_fooo3157=== CONT TestGlobMatch/foo*_foo3158=== CONT TestGlobMatch/foo*_bar3159=== CONT TestGlobMatch/*/*_foo3160=== CONT TestGlobMatch/*_anything3161=== CONT TestGlobMatch/?oo_boo3162=== CONT TestGlobMatch/?oo_foo3163=== CONT TestGlobMatch/foo_bar3164=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03165=== CONT TestGlobMatch/*bar_foobar3166=== CONT TestGlobMatch/*bar_bar3167=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3168=== CONT TestGlobMatch/*/*_foo/bar3169=== CONT TestGlobMatch/foo*bar_foobarbaz3170=== CONT TestGlobMatch/fo?_fo3171=== CONT TestGlobMatch/foo*_foobar3172=== CONT TestGlobMatch/fo?_foo3173=== CONT TestGlobMatch/foo*bar_foobar3174=== CONT TestGlobMatch/*_3175=== CONT TestGlobMatch/*bar_foo3176--- PASS: TestGlobMatch (0.01s)3177 --- PASS: TestGlobMatch/foo_foo (0.00s)3178 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3179 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3180 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3181 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3182 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3183 --- PASS: TestGlobMatch/foo*_foo (0.00s)3184 --- PASS: TestGlobMatch/foo*_bar (0.00s)3185 --- PASS: TestGlobMatch/*/*_foo (0.00s)3186 --- PASS: TestGlobMatch/*_anything (0.00s)3187 --- PASS: TestGlobMatch/?oo_boo (0.00s)3188 --- PASS: TestGlobMatch/?oo_foo (0.00s)3189 --- PASS: TestGlobMatch/foo_bar (0.00s)3190 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3191 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3192 --- PASS: TestGlobMatch/*bar_bar (0.00s)3193 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3194 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3195 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3196 --- PASS: TestGlobMatch/fo?_fo (0.00s)3197 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3198 --- PASS: TestGlobMatch/fo?_foo (0.00s)3199 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3200 --- PASS: TestGlobMatch/*_ (0.00s)3201 --- PASS: TestGlobMatch/*bar_foo (0.00s)32022026/10/01 09:34:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4641332032026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38475/oidc3204--- PASS: TestPins_TopLevelShorthand (0.03s)32052026/10/01 09:34:04 http: TLS handshake error from 127.0.0.1:47264: remote error: tls: bad certificate3206--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)3207--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)32082026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41785/oidc3209--- PASS: TestValidateToken_Expired (0.05s)32102026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42123/oidc3211--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)32122026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41969/oidc3213--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)32142026/10/01 09:34:04 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12332152026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34833/oidc32162026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43827/oidc3217--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)3218--- PASS: TestValidateToken_ValidToken (0.07s)32192026/10/01 09:34:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42651/oidc32202026/10/01 09:34:04 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42613/oidc32212026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35387/oidc32222026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41029/oidc3223--- PASS: TestScopes_Rules (0.07s)3224--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)3225--- PASS: TestValidateToken_MultipleProviders (0.07s)3226--- PASS: TestPins_ReservedForMatchingRule (0.07s)32272026/10/01 09:34:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38645/oidc3228--- PASS: TestValidateToken_WrongAudience (0.09s)32292026/10/01 09:34:04 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41153/oidc3230--- PASS: TestValidateToken_NoMatchingProvider (0.21s)3231PASS3232Running hook tests...3233=== RUN TestSendPathsEmpty3234=== PAUSE TestSendPathsEmpty3235=== RUN TestQueueEnqueueAndFetch3236=== PAUSE TestQueueEnqueueAndFetch3237=== RUN TestQueueDeduplication3238=== PAUSE TestQueueDeduplication3239=== RUN TestQueueRemove3240=== PAUSE TestQueueRemove3241=== RUN TestQueueFetchBatchLimit3242=== PAUSE TestQueueFetchBatchLimit3243=== RUN TestQueueRetryMovesToBack3244=== PAUSE TestQueueRetryMovesToBack3245=== RUN TestQueueFetchRemoveLifecycle3246=== PAUSE TestQueueFetchRemoveLifecycle3247=== RUN TestQueueConcurrentWriters3248=== PAUSE TestQueueConcurrentWriters3249=== RUN TestQueueRemoveLargeClosure3250=== PAUSE TestQueueRemoveLargeClosure3251=== RUN TestServerClientIntegration3252=== PAUSE TestServerClientIntegration3253=== RUN TestServerQueueError3254=== PAUSE TestServerQueueError3255=== RUN TestGetListenerSocketActivation3256 server_test.go:210: === RUN TestGetListenerSocketActivation3257 --- PASS: TestGetListenerSocketActivation (0.00s)3258 PASS3259 3260--- PASS: TestGetListenerSocketActivation (0.01s)3261=== RUN TestDrainIsolatesPoisonPath3262=== PAUSE TestDrainIsolatesPoisonPath3263=== RUN TestRunNotBlockedByPoisonHead3264=== PAUSE TestRunNotBlockedByPoisonHead3265=== RUN TestDrainGivesUpWhenServerDown3266=== PAUSE TestDrainGivesUpWhenServerDown3267=== RUN TestFailedPathPrunedByLaterClosure3268=== PAUSE TestFailedPathPrunedByLaterClosure3269=== RUN TestWorkerUploadsAndRemoves3270=== PAUSE TestWorkerUploadsAndRemoves3271=== RUN TestWorkerSkipsGCdPaths3272=== PAUSE TestWorkerSkipsGCdPaths3273=== RUN TestWorkerPrunesClosureDeps3274=== PAUSE TestWorkerPrunesClosureDeps3275=== RUN TestDrainTimeout3276=== PAUSE TestDrainTimeout3277=== CONT TestSendPathsEmpty3278=== CONT TestServerQueueError3279--- PASS: TestSendPathsEmpty (0.00s)3280=== CONT TestQueueFetchBatchLimit3281=== CONT TestQueueRemove3282=== CONT TestQueueDeduplication3283=== CONT TestQueueEnqueueAndFetch3284=== CONT TestQueueRetryMovesToBack32852026/10/01 09:34:04 ERROR Failed to queue paths error="permission denied" count=13286=== CONT TestQueueRemoveLargeClosure3287=== CONT TestQueueConcurrentWriters3288--- PASS: TestServerQueueError (0.00s)3289=== CONT TestWorkerUploadsAndRemoves3290=== CONT TestDrainTimeout3291=== CONT TestWorkerPrunesClosureDeps3292=== CONT TestQueueFetchRemoveLifecycle3293=== CONT TestWorkerSkipsGCdPaths3294=== CONT TestDrainGivesUpWhenServerDown3295=== CONT TestRunNotBlockedByPoisonHead3296=== CONT TestFailedPathPrunedByLaterClosure3297=== CONT TestDrainIsolatesPoisonPath3298=== CONT TestServerClientIntegration3299--- PASS: TestServerClientIntegration (0.00s)33002026/10/01 09:34:04 INFO Uploading batch count=433012026/10/01 09:34:04 INFO Upload queue status pending=233022026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=433032026/10/01 09:34:04 INFO Upload queue status pending=233042026/10/01 09:34:04 INFO Uploading batch count=233052026/10/01 09:34:04 INFO Upload queue status pending=233062026/10/01 09:34:04 INFO Uploading batch count=133072026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=133082026/10/01 09:34:04 INFO Uploading batch count=23309--- PASS: TestQueueEnqueueAndFetch (0.02s)33102026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=233112026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3701316608/002/a33122026/10/01 09:34:04 INFO Uploading batch count=233132026/10/01 09:34:04 INFO Uploading batch count=133142026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath215013363/002/bbb33152026/10/01 09:34:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2334070601/002/nonexistent33162026/10/01 09:34:04 INFO Uploading batch count=13317--- PASS: TestQueueDeduplication (0.02s)33182026/10/01 09:34:04 INFO Upload queue status pending=333192026/10/01 09:34:04 INFO Uploading batch count=13320--- PASS: TestQueueRemove (0.02s)33212026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=13322--- PASS: TestQueueFetchBatchLimit (0.02s)33232026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3701316608/002/b33242026/10/01 09:34:04 INFO Uploading batch count=133252026/10/01 09:34:04 INFO Uploading batch count=13326--- PASS: TestQueueRetryMovesToBack (0.02s)3327--- PASS: TestQueueFetchRemoveLifecycle (0.02s)33282026/10/01 09:34:04 INFO Uploading batch count=233292026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=233302026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3701316608/002/c33312026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3701316608/002/d33322026/10/01 09:34:04 INFO Uploading batch count=133332026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=13334--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)33352026/10/01 09:34:04 INFO Uploading batch count=233362026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=233372026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3701316608/002/e33382026/10/01 09:34:04 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3701316608/002/f33392026/10/01 09:34:04 INFO Uploading batch count=133402026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=133412026/10/01 09:34:04 ERROR Drain finished with paths left in queue remaining=1033422026/10/01 09:34:04 INFO Uploading batch count=133432026/10/01 09:34:04 ERROR Upload failed error="upload failed" count=133442026/10/01 09:34:04 ERROR Drain finished with paths left in queue remaining=13345--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3346--- PASS: TestDrainIsolatesPoisonPath (0.03s)3347--- PASS: TestWorkerUploadsAndRemoves (0.04s)3348--- PASS: TestWorkerSkipsGCdPaths (0.04s)3349--- PASS: TestWorkerPrunesClosureDeps (0.04s)3350--- PASS: TestQueueRemoveLargeClosure (0.09s)33512026/10/01 09:34:04 ERROR Upload failed error="context deadline exceeded" count=233522026/10/01 09:34:04 ERROR Drain finished with paths left in queue remaining=43353--- PASS: TestDrainTimeout (0.22s)3354--- PASS: TestQueueConcurrentWriters (0.28s)33552026/10/01 09:34:05 INFO Uploading batch count=133562026/10/01 09:34:05 INFO Uploading batch count=133572026/10/01 09:34:05 INFO Uploading batch count=133582026/10/01 09:34:05 ERROR Upload failed error="upload failed" count=133592026/10/01 09:34:05 INFO Uploading batch count=133602026/10/01 09:34:05 ERROR Upload failed error="upload failed" count=133612026/10/01 09:34:05 INFO Uploading batch count=133622026/10/01 09:34:05 ERROR Upload failed error="upload failed" count=133632026/10/01 09:34:05 INFO Uploading batch count=133642026/10/01 09:34:05 ERROR Upload failed error="upload failed" count=133652026/10/01 09:34:05 ERROR Drain finished with paths left in queue remaining=13366--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3367PASS

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

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