niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #284
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestStreamPushBatchesUnderLoad98=== CONT TestScriptTokenEmptyCommand99--- PASS: TestScriptTokenEmptyCommand (0.00s)100=== CONT TestResolveStorePath101=== CONT TestSetClientTLSDoesNotMutateDefaultTransport102=== CONT TestSetClientTLS103=== CONT TestScriptTokenBadJSON104=== CONT TestClientSignaturesByStorePath105=== CONT TestScriptTokenEmptyToken106=== CONT TestStreamPushReportsSignatures107=== CONT TestScriptTokenCachesUntilRefresh108=== CONT TestStreamPushRequestLine109=== CONT TestScriptTokenNoExpiryRerunsEveryCall110=== CONT TestStreamPushGivesUpOnDeadServer111=== CONT TestFileTokenEmpty112=== CONT TestStreamPushIsolatesFailures113=== CONT TestFileTokenMissing114=== CONT TestFileTokenReadsAndCaches1152026/10/01 07:32:58 ERROR Upload failed error="connection refused" count=201162026/10/01 07:32:58 ERROR Server seems unavailable, giving up on batch untried=17117=== CONT TestStaticToken1182026/10/01 07:32:58 ERROR Upload failed error=boom count=1119=== CONT TestPathInfoHashCompatibility120=== CONT TestSetClientTLSErrors121=== CONT TestShellSplitErrors122=== CONT TestStreamPushReportsEveryPath123=== CONT TestParsePathInfoJSONMultiplePaths1242026/10/01 07:32:58 ERROR Upload failed error="bad path" count=3125=== CONT TestDoWithRetry_BodyReplayedViaGetBody126--- PASS: TestClientSignaturesByStorePath (0.00s)127=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess128=== CONT TestRateLimiterFeedback129=== CONT TestPathInfoCACompatibility130=== CONT TestUploadMultipart_SupersededByPeer131=== RUN TestRateLimiterFeedback/429_enables_limiter132=== PAUSE TestRateLimiterFeedback/429_enables_limiter133=== RUN TestUploadMultipart_SupersededByPeer/exists1342026/10/01 07:32:58 ERROR Upload failed error=boom count=1135=== PAUSE TestUploadMultipart_SupersededByPeer/exists136=== CONT TestPartSizeForNAR1372026/10/01 07:32:58 WARN Rate limiter enabled after throttle name=server-test rate=5138=== RUN TestUploadMultipart_SupersededByPeer/missing139=== PAUSE TestUploadMultipart_SupersededByPeer/missing140=== CONT TestShellSplit141=== CONT TestUploadMultipart_PartsInParallel142=== RUN TestPartSizeForNAR/zero_stays_at_minimum143=== CONT TestGetStorePathHash144=== RUN TestGetStorePathHash/valid_store_path145=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)146=== CONT TestDumpPathWriterError147=== CONT TestParsePathInfoJSON148=== CONT TestDumpPathSingleFile149--- PASS: TestResolveStorePath (0.00s)150=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== CONT TestEncodeNixBase32152=== RUN TestEncodeNixBase32/test_string_hash153=== CONT TestDumpPathMatchesNix154=== PAUSE TestGetStorePathHash/valid_store_path155=== RUN TestRateLimiterFeedback/503_enables_limiter156=== PAUSE TestRateLimiterFeedback/503_enables_limiter157=== CONT TestFilterOversizedClosures158=== RUN TestFilterOversizedClosures/no_limit_keeps_everything159=== RUN TestPathInfoCACompatibility/null_ca_field160=== RUN TestSetClientTLSErrors/missing_cert_file161=== CONT TestCaseHackSuffix162=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum163--- PASS: TestScriptTokenScriptFails (0.00s)164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165--- PASS: TestStaticToken (0.00s)166--- PASS: TestStreamPushReportsSignatures (0.00s)167=== PAUSE TestEncodeNixBase32/test_string_hash1682026/10/01 07:32:58 WARN Rate limiter enabled after throttle name=server-test rate=5169=== RUN TestParsePathInfoJSON/Nix_format170=== RUN TestGetStorePathHash/basename_without_hyphen_should_error171=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter172=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths173=== CONT TestConvertHashToNix321742026/10/01 07:32:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43901175=== CONT TestRegisterUploadedObjectReusesConnections176=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything177=== RUN TestSetClientTLS/rejects_connection_without_client_cert178=== CONT TestEncodeNixBase32WithRealHash179=== PAUSE TestPathInfoCACompatibility/null_ca_field180=== CONT TestUploadMultipart_SupersededByPeer/exists181=== CONT TestUploadMultipart_SupersededByPeer/missing1822026/10/01 07:32:58 WARN Rate limiter backed off name=server-test rate=51832026/10/01 07:32:58 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43901184=== RUN TestPartSizeForNAR/small_stays_at_minimum185=== PAUSE TestPartSizeForNAR/small_stays_at_minimum186=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum187=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum188=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts189=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon190=== PAUSE TestSetClientTLSErrors/missing_cert_file191--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)192=== RUN TestEncodeNixBase32/empty_input193=== PAUSE TestParsePathInfoJSON/Nix_format194=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error195=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter196=== RUN TestConvertHashToNix32/SRI_format_to_Nix32197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped199=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert200=== RUN TestPathInfoCACompatibility/old_string_format_-_text201=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text202=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive203=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive204=== RUN TestPathInfoCACompatibility/new_structured_format_-_text205=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text206=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method207=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method208=== CONT TestPathInfoCACompatibility/null_ca_field209=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts210=== RUN TestPartSizeForNAR/1_TiB211=== PAUSE TestPartSizeForNAR/1_TiB212=== RUN TestPartSizeForNAR/5_TiB_S3_max_object213=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object214=== RUN TestPartSizeForNAR/capped_at_5_GiB215=== PAUSE TestPartSizeForNAR/capped_at_5_GiB216=== CONT TestPartSizeForNAR/zero_stays_at_minimum217=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon218=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI219=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI220=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512221=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512222=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)223=== RUN TestSetClientTLSErrors/missing_key_file224=== PAUSE TestSetClientTLSErrors/missing_key_file225=== RUN TestSetClientTLSErrors/missing_ca_file226=== PAUSE TestSetClientTLSErrors/missing_ca_file227=== RUN TestSetClientTLSErrors/invalid_ca_file228=== PAUSE TestSetClientTLSErrors/invalid_ca_file229=== CONT TestSetClientTLSErrors/missing_cert_file230=== CONT TestPathInfoCACompatibility/old_string_format_-_text231=== CONT TestPartSizeForNAR/1_TiB232--- PASS: TestFileTokenEmpty (0.00s)233--- PASS: TestScriptTokenEmptyToken (0.00s)234--- PASS: TestShellSplitErrors (0.00s)235--- PASS: TestFileTokenReadsAndCaches (0.00s)236--- PASS: TestStreamPushReportsEveryPath (0.00s)237--- PASS: TestScriptTokenBadJSON (0.00s)238--- PASS: TestStreamPushIsolatesFailures (0.00s)239--- PASS: TestShellSplit (0.00s)240--- PASS: TestFileTokenMissing (0.00s)241--- PASS: TestDoServerRequestAttachesToken (0.01s)242=== RUN TestParsePathInfoJSON/Lix_format243=== PAUSE TestParsePathInfoJSON/Lix_format244=== RUN TestParsePathInfoJSON/empty_input245=== PAUSE TestParsePathInfoJSON/empty_input246=== RUN TestParsePathInfoJSON/whitespace_only247=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512248=== CONT TestSetClientTLSErrors/missing_ca_file249=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error250=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error251=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error252=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error253=== CONT TestSetClientTLSErrors/missing_key_file254=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum255=== CONT TestPathInfoCACompatibility/new_structured_format_-_text256=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method257=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive258=== CONT TestGetStorePathHash/valid_store_path259=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error260=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error261=== CONT TestGetStorePathHash/basename_without_hyphen_should_error262=== PAUSE TestEncodeNixBase32/empty_input263=== CONT TestEncodeNixBase32/test_string_hash264=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths265=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths266=== CONT TestEncodeNixBase32/empty_input267=== CONT TestPartSizeForNAR/capped_at_5_GiB268=== CONT TestPartSizeForNAR/5_TiB_S3_max_object269=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32270=== RUN TestConvertHashToNix32/already_Nix32_format271=== PAUSE TestConvertHashToNix32/already_Nix32_format272=== RUN TestConvertHashToNix32/invalid_format273=== PAUSE TestConvertHashToNix32/invalid_format274=== CONT TestConvertHashToNix32/SRI_format_to_Nix32275=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths276=== CONT TestConvertHashToNix32/invalid_format277=== CONT TestConvertHashToNix32/already_Nix32_format278=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI279=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon280=== CONT TestPartSizeForNAR/small_stays_at_minimum281=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped282=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA283=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA284=== RUN TestSetClientTLS/preserves_debug_logging_transport285=== PAUSE TestSetClientTLS/preserves_debug_logging_transport286--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)287--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)288=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter289=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter290=== CONT TestRateLimiterFeedback/429_enables_limiter291=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter292=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter293=== PAUSE TestParsePathInfoJSON/whitespace_only294=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts295=== RUN TestFilterOversizedClosures/all_closures_skipped296=== PAUSE TestFilterOversizedClosures/all_closures_skipped297=== CONT TestFilterOversizedClosures/no_limit_keeps_everything298--- PASS: TestEncodeNixBase32WithRealHash (0.00s)299--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)300--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)301=== CONT TestFilterOversizedClosures/all_closures_skipped3022026/10/01 07:32:58 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50303=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3042026/10/01 07:32:58 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=2000305=== CONT TestSetClientTLS/rejects_connection_without_client_cert3062026/10/01 07:32:58 WARN Rate limiter enabled after throttle name=server-test rate=5307=== CONT TestSetClientTLS/preserves_debug_logging_transport308--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)309 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)310 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3112026/10/01 07:32:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34385312--- PASS: TestPathInfoCACompatibility (0.04s)313 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)314 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)315 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)316 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)317 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)318--- PASS: TestGetStorePathHash (0.04s)319 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)320 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)321 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)322 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)323--- PASS: TestEncodeNixBase32 (0.04s)324 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)325 --- PASS: TestEncodeNixBase32/empty_input (0.00s)326--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)327 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3292026/10/01 07:32:58 WARN Rate limiter backed off name=server-test rate=5330--- PASS: TestConvertHashToNix32 (0.00s)331 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)332 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)333 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)334--- PASS: TestPathInfoHashCompatibility (0.04s)335 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)336 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)337 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)338 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)339--- PASS: TestPartSizeForNAR (0.04s)340 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)341 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)342 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)343 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)344 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)345 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)346 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)347--- PASS: TestFilterOversizedClosures (0.04s)348 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)349 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)350 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)351=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA352=== CONT TestRateLimiterFeedback/503_enables_limiter353=== RUN TestParsePathInfoJSON/invalid_JSON354=== PAUSE TestParsePathInfoJSON/invalid_JSON355=== CONT TestParsePathInfoJSON/Nix_format356=== CONT TestSetClientTLSErrors/invalid_ca_file3572026/10/01 07:32:58 WARN Rate limiter enabled after throttle name=server-test rate=5358=== CONT TestParsePathInfoJSON/whitespace_only3592026/10/01 07:32:58 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46877360=== CONT TestParsePathInfoJSON/invalid_JSON3612026/10/01 07:32:58 WARN Rate limiter backed off name=server-test rate=5362--- PASS: TestRateLimiterFeedback (0.04s)363 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)364 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)365 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)366 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)367--- PASS: TestSetClientTLSErrors (0.04s)368 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)370 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)371 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)372=== CONT TestParsePathInfoJSON/empty_input373=== CONT TestParsePathInfoJSON/Lix_format374--- PASS: TestParsePathInfoJSON (0.04s)375 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)376 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)377 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)378 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)379 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3802026/10/01 07:32:58 http: TLS handshake error from 127.0.0.1:54570: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.05s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)385--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)386--- PASS: TestCaseHackSuffix (0.03s)387--- PASS: TestDumpPathSingleFile (0.07s)388--- PASS: TestStreamPushRequestLine (0.07s)389--- PASS: TestDumpPathWriterError (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres4095622069/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/postgres4095622069/data -l logfile start422423/build/postgres4095622069:5432 - no response4242026-10-01 07:33:00.107 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 07:33:00.108 UTC [130] LOG: listening on Unix socket "/build/postgres4095622069/.s.PGSQL.5432"4262026-10-01 07:33:00.112 UTC [137] LOG: database system was shut down at 2026-10-01 07:32:59 UTC4272026-10-01 07:33:00.116 UTC [130] LOG: database system is ready to accept connections428/build/postgres4095622069:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-10-01 07:33:00.492 UTC [372] ERROR: relation "goose_db_version" does not exist at character 364712026-10-01 07:33:00.492 UTC [372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/10/01 07:33:00 OK 20241026095416_initial_model.sql (10.74ms)4732026/10/01 07:33:00 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)4742026/10/01 07:33:00 OK 20251218171726_add_pins.sql (3.23ms)4752026/10/01 07:33:00 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)4762026/10/01 07:33:00 OK 20260905000000_add_claims.sql (3.12ms)4772026/10/01 07:33:00 OK 20260920000000_drop_claims.sql (1.91ms)4782026/10/01 07:33:00 OK 20260923120000_add_pushes.sql (1.46ms)4792026/10/01 07:33:00 goose: successfully migrated database to version: 202609231200004802026/10/01 07:33:00 OK 1_commit_pending_closure.sql (1.81ms)4812026/10/01 07:33:00 OK 2_object_stats_trigger.sql (794.73µs)4822026/10/01 07:33:00 OK 3_commit_push.sql (619.35µs)4832026/10/01 07:33:00 goose: up to current file version: 34842026/10/01 07:33:00 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 07:33:01 INFO lead: released remote=192.0.2.1:12344862026/10/01 07:33:01 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 07:33:01 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-10-01 07:33:01.265 UTC [382] ERROR: relation "goose_db_version" does not exist at character 364932026-10-01 07:33:01.265 UTC [382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/10/01 07:33:01 OK 20241026095416_initial_model.sql (9.32ms)4952026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)4962026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.38ms)4972026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)4982026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.23ms)4992026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (1.97ms)5002026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.71ms)5012026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200005022026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.4ms)5032026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.07ms)5042026/10/01 07:33:01 OK 3_commit_push.sql (582.75µs)5052026/10/01 07:33:01 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestGCTaskStore_StartNew526=== PAUSE TestGCTaskStore_StartNew527=== RUN TestGCTaskStore_DeduplicateSameParams528=== PAUSE TestGCTaskStore_DeduplicateSameParams529=== RUN TestGCTaskStore_ConflictDifferentParams530=== PAUSE TestGCTaskStore_ConflictDifferentParams531=== RUN TestGCTaskStore_GetEmpty532=== PAUSE TestGCTaskStore_GetEmpty533=== RUN TestGCTaskStore_GetReturnsLatest534=== PAUSE TestGCTaskStore_GetReturnsLatest535=== RUN TestGCTaskStore_CompletedAllowsNewTask536=== PAUSE TestGCTaskStore_CompletedAllowsNewTask537=== RUN TestGCTaskStore_PhaseUpdates538=== PAUSE TestGCTaskStore_PhaseUpdates539=== RUN TestGCTaskStore_Fail540=== PAUSE TestGCTaskStore_Fail541=== RUN TestGracefulShutdownDrainsInflight542=== PAUSE TestGracefulShutdownDrainsInflight543=== RUN TestService_healthCheckHandler544=== PAUSE TestService_healthCheckHandler545=== RUN TestService_readinessHandler546=== PAUSE TestService_readinessHandler547=== RUN TestGenerateLandingPage548=== PAUSE TestGenerateLandingPage549=== RUN TestCacheConfigHandlerMaxNarSize550=== PAUSE TestCacheConfigHandlerMaxNarSize551=== RUN TestCreatePendingClosureRejectsOversizedNAR552=== PAUSE TestCreatePendingClosureRejectsOversizedNAR553=== RUN TestNARDeduplicationMetadataUploadBug554=== PAUSE TestNARDeduplicationMetadataUploadBug555=== RUN TestMetricsInventory556=== PAUSE TestMetricsInventory557=== RUN TestService_NativeMTLS558=== PAUSE TestService_NativeMTLS559=== RUN TestServerTLSConfig560=== PAUSE TestServerTLSConfig561=== RUN TestMultipartCleanup562=== PAUSE TestMultipartCleanup563=== RUN TestObjectStatsTrigger564=== PAUSE TestObjectStatsTrigger565=== RUN TestOrphanedObjectsGC566=== PAUSE TestOrphanedObjectsGC567=== RUN TestOrphanedObjectsGCStressTest568=== PAUSE TestOrphanedObjectsGCStressTest569=== RUN TestCreatePin_ReservedPins570=== PAUSE TestCreatePin_ReservedPins571=== RUN TestParseSingleRange572=== PAUSE TestParseSingleRange573=== RUN TestProxyHeadersOnlyTrustedOnSocket574=== PAUSE TestProxyHeadersOnlyTrustedOnSocket575=== RUN TestIsValidCachePath576=== PAUSE TestIsValidCachePath577=== RUN TestReadProxyNarinfo578=== PAUSE TestReadProxyNarinfo579=== RUN TestReadProxyNarinfoAlreadyDecompressed580=== PAUSE TestReadProxyNarinfoAlreadyDecompressed581=== RUN TestReadProxyNarStreaming582=== PAUSE TestReadProxyNarStreaming583=== RUN TestReadProxy404584=== PAUSE TestReadProxy404585=== RUN TestReadProxyInvalidPath586=== PAUSE TestReadProxyInvalidPath587=== RUN TestReadProxyHead588=== PAUSE TestReadProxyHead589=== RUN TestReadProxyConditionalGet590=== PAUSE TestReadProxyConditionalGet591=== RUN TestReadProxyRootRedirectsToIndexHTML592=== PAUSE TestReadProxyRootRedirectsToIndexHTML593=== RUN TestReadProxyDisabled594=== PAUSE TestReadProxyDisabled595=== RUN TestReadRedirectNar596=== PAUSE TestReadRedirectNar597=== RUN TestReadRedirectKeepsNarinfoProxied598=== PAUSE TestReadRedirectKeepsNarinfoProxied599=== RUN TestReadProxyRangeRequest600=== PAUSE TestReadProxyRangeRequest601=== RUN TestReadRedirectUsesPublicS3URL602=== PAUSE TestReadRedirectUsesPublicS3URL603=== RUN TestPush_OverlappingRootsStoreOneRowPerKey604=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey605=== RUN TestPush_CompleteCommitsEveryRoot606=== PAUSE TestPush_CompleteCommitsEveryRoot607=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit608=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit609=== RUN TestPush_RejectsBadRequests610=== PAUSE TestPush_RejectsBadRequests611=== RUN TestPush_SignsNarinfosOfItsPendingObjects612=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects613=== RUN TestRedundantMultipartUpload614=== PAUSE TestRedundantMultipartUpload615=== RUN TestCompleteMultipartUpload_ErrorButObjectExists616=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists617=== RUN TestCompletedNarNotReofferedAcrossClosures618=== PAUSE TestCompletedNarNotReofferedAcrossClosures619=== RUN TestPresignedUploadRegisteredBeforeCommit620=== PAUSE TestPresignedUploadRegisteredBeforeCommit621=== RUN TestService_Rustfstest622=== PAUSE TestService_Rustfstest623=== RUN TestParseSize624=== PAUSE TestParseSize625=== RUN TestSkippedUploadsHandler626=== PAUSE TestSkippedUploadsHandler627=== RUN TestSystemdListenerNotActivated628--- PASS: TestSystemdListenerNotActivated (0.00s)629=== RUN TestWatchdogBeatsWhenHealthy630--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)631=== RUN TestWatchdogSkipsWhenUnhealthy6322026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6332026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6342026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:33:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"642--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)643=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle644=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle645=== RUN TestProxyWriteTimeout646=== PAUSE TestProxyWriteTimeout647=== RUN TestIsValidUploadKey648=== PAUSE TestIsValidUploadKey649=== RUN TestUploadHandlersRejectInvalidKeys650=== PAUSE TestUploadHandlersRejectInvalidKeys651=== RUN TestUploadHandlersRejectOversizedBody652=== PAUSE TestUploadHandlersRejectOversizedBody653=== RUN TestService_cleanupPendingClosuresHandler654=== PAUSE TestService_cleanupPendingClosuresHandler655=== RUN TestService_createPendingClosureHandler656=== PAUSE TestService_createPendingClosureHandler657=== RUN TestService_verifyS3Integrity658=== PAUSE TestService_verifyS3Integrity659=== RUN TestCompleteMultipartUnregistered660=== PAUSE TestCompleteMultipartUnregistered661=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT662=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT663=== CONT TestService_AuthMiddleware664=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT665=== CONT TestGracefulShutdownDrainsInflight666=== CONT TestSkippedUploadsHandler667=== CONT TestPushDedupSurvivesConcurrentGC668=== CONT TestReadRedirectUsesPublicS3URL6692026/10/01 07:33:01 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000670=== CONT TestClientMultipleUploads6712026/10/01 07:33:01 INFO Starting HTTP server address=127.0.0.1:36441672=== CONT TestMetricsInventory673=== CONT TestNARDeduplicationMetadataUploadBug674=== CONT TestCreatePendingClosureRejectsOversizedNAR675=== CONT TestCacheConfigHandlerMaxNarSize6762026/10/01 07:33:01 INFO Shutdown signal received, draining in-flight requests timeout=10s677=== CONT TestGenerateLandingPage678=== CONT TestService_readinessHandler6792026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures680=== CONT TestService_healthCheckHandler681=== CONT TestCompleteMultipartUnregistered682=== CONT TestGCBugBareHashReferences683=== CONT TestService_verifyS3Integrity684=== CONT TestService_createPendingClosureHandler685=== CONT TestService_cleanupPendingClosuresHandler686=== CONT TestUploadHandlersRejectOversizedBody687=== CONT TestUploadHandlersRejectInvalidKeys688=== CONT TestIsValidUploadKey689=== CONT TestProxyWriteTimeout690=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle691=== CONT TestService_NativeMTLS692=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info693=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info694=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal695=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal696=== RUN TestIsValidUploadKey/narinfo697=== PAUSE TestIsValidUploadKey/narinfo698=== RUN TestIsValidUploadKey/nar_zst699=== CONT TestGCMetrics700=== PAUSE TestIsValidUploadKey/nar_zst701=== RUN TestIsValidUploadKey/nar_xz702=== PAUSE TestIsValidUploadKey/nar_xz703=== RUN TestIsValidUploadKey/nar_plain704=== RUN TestProxyWriteTimeout/narinfo705--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)706--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)707=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key708--- PASS: TestGenerateLandingPage (0.01s)709=== CONT TestLeadEndsOnShutdown710=== PAUSE TestIsValidUploadKey/nar_plain711=== RUN TestIsValidUploadKey/listing712=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key713=== PAUSE TestIsValidUploadKey/listing714=== PAUSE TestProxyWriteTimeout/narinfo715=== RUN TestIsValidUploadKey/build_log716=== RUN TestProxyWriteTimeout/1_GiB_nar717=== PAUSE TestProxyWriteTimeout/1_GiB_nar718=== RUN TestProxyWriteTimeout/10_GiB_nar719=== PAUSE TestProxyWriteTimeout/10_GiB_nar720=== RUN TestProxyWriteTimeout/unknown_size721=== PAUSE TestProxyWriteTimeout/unknown_size722=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key723=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key724=== PAUSE TestIsValidUploadKey/build_log725--- PASS: TestSkippedUploadsHandler (0.07s)726=== CONT TestLeadElectsOneAndHandsOver727=== CONT TestResolveDBConnectionString728=== CONT TestClientFallsBackToClosures729=== RUN TestIsValidUploadKey/build_log_home-manager_file730=== PAUSE TestIsValidUploadKey/build_log_home-manager_file731=== RUN TestIsValidUploadKey/build_log_plus_in_name732=== PAUSE TestIsValidUploadKey/build_log_plus_in_name733=== RUN TestIsValidUploadKey/build_log_question_mark734=== PAUSE TestIsValidUploadKey/build_log_question_mark735=== RUN TestIsValidUploadKey/build_log_equals736=== PAUSE TestIsValidUploadKey/build_log_equals737=== RUN TestIsValidUploadKey/realisation738=== PAUSE TestIsValidUploadKey/realisation739=== RUN TestIsValidUploadKey/realisation_plus_in_output740=== RUN TestResolveDBConnectionString/flag_wins741=== PAUSE TestIsValidUploadKey/realisation_plus_in_output742=== RUN TestIsValidUploadKey/nix-cache-info743=== PAUSE TestIsValidUploadKey/nix-cache-info744=== RUN TestIsValidUploadKey/index.html745=== PAUSE TestResolveDBConnectionString/flag_wins746=== PAUSE TestIsValidUploadKey/index.html747=== RUN TestResolveDBConnectionString/file_when_flag_empty748=== RUN TestIsValidUploadKey/narinfo_key,_nar_type749=== PAUSE TestResolveDBConnectionString/file_when_flag_empty750=== RUN TestResolveDBConnectionString/missing_file_is_an_error751=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type752=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error753=== RUN TestResolveDBConnectionString/PGHOST_allows_empty754=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty755=== RUN TestIsValidUploadKey/nar_key,_narinfo_type756=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type757=== RUN TestResolveDBConnectionString/nothing_configured758=== PAUSE TestResolveDBConnectionString/nothing_configured759=== RUN TestIsValidUploadKey/listing_key,_narinfo_type760=== CONT TestClientPushesUseOnePush761=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type762=== RUN TestIsValidUploadKey/traversal763=== PAUSE TestIsValidUploadKey/traversal764=== RUN TestIsValidUploadKey/traversal_nar765=== PAUSE TestIsValidUploadKey/traversal_nar766=== RUN TestIsValidUploadKey/absolute767=== PAUSE TestIsValidUploadKey/absolute768=== RUN TestIsValidUploadKey/empty_key769=== PAUSE TestIsValidUploadKey/empty_key770=== RUN TestIsValidUploadKey/unknown_type771=== PAUSE TestIsValidUploadKey/unknown_type772=== CONT TestPinProtectsFromGC773--- PASS: TestGracefulShutdownDrainsInflight (0.07s)774=== CONT TestClientSharedPathCommittedMidPush7752026-10-01 07:33:01.653 UTC [448] ERROR: relation "goose_db_version" does not exist at character 367762026-10-01 07:33:01.653 UTC [448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-10-01 07:33:01.653 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367782026-10-01 07:33:01.653 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026-10-01 07:33:01.681 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367802026-10-01 07:33:01.681 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026-10-01 07:33:01.690 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367822026-10-01 07:33:01.690 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026-10-01 07:33:01.691 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367842026-10-01 07:33:01.691 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7852026-10-01 07:33:01.694 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367862026-10-01 07:33:01.694 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026-10-01 07:33:01.700 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367882026-10-01 07:33:01.700 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC789=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure790=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure791=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart792=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart793=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts794=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts795=== CONT TestClientWithDependencies7962026/10/01 07:33:01 OK 20241026095416_initial_model.sql (30.84ms)7972026/10/01 07:33:01 OK 20241026095416_initial_model.sql (30.03ms)7982026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)7992026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)8002026/10/01 07:33:01 OK 20251218171726_add_pins.sql (6.74ms)8012026/10/01 07:33:01 OK 20241026095416_initial_model.sql (15.31ms)8022026/10/01 07:33:01 OK 20241026095416_initial_model.sql (19.83ms)8032026-10-01 07:33:01.726 UTC [458] ERROR: relation "goose_db_version" does not exist at character 368042026-10-01 07:33:01.726 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026/10/01 07:33:01 OK 20251218171726_add_pins.sql (15.03ms)8062026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (10.51ms)8072026/10/01 07:33:01 OK 20241026095416_initial_model.sql (25.51ms)8082026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (10.86ms)8092026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (10.75ms)8102026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (3.53ms)8112026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (7.1ms)8122026/10/01 07:33:01 OK 20260905000000_add_claims.sql (6.7ms)8132026/10/01 07:33:01 OK 20251218171726_add_pins.sql (6.47ms)8142026/10/01 07:33:01 OK 20251218171726_add_pins.sql (6.46ms)8152026/10/01 07:33:01 OK 20241026095416_initial_model.sql (26.6ms)8162026/10/01 07:33:01 OK 20241026095416_initial_model.sql (27.46ms)8172026/10/01 07:33:01 OK 20251218171726_add_pins.sql (5.37ms)8182026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)8192026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)8202026-10-01 07:33:01.745 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368212026-10-01 07:33:01.745 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-10-01 07:33:01.745 UTC [459] ERROR: relation "goose_db_version" does not exist at character 368232026-10-01 07:33:01.745 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (4.72ms)8252026/10/01 07:33:01 OK 20260905000000_add_claims.sql (5.9ms)8262026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.96ms)8272026-10-01 07:33:01.747 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368282026-10-01 07:33:01.747 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (7.18ms)8302026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)8312026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (4.02ms)8322026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200008332026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (4.14ms)8342026-10-01 07:33:01.754 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368352026-10-01 07:33:01.754 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8362026-10-01 07:33:01.754 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368372026-10-01 07:33:01.754 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026-10-01 07:33:01.756 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368392026-10-01 07:33:01.756 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026/10/01 07:33:01 OK 20251218171726_add_pins.sql (23.81ms)8412026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (21.55ms)8422026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200008432026/10/01 07:33:01 OK 20260905000000_add_claims.sql (23.43ms)8442026/10/01 07:33:01 OK 1_commit_pending_closure.sql (21.98ms)8452026/10/01 07:33:01 OK 20260905000000_add_claims.sql (24.71ms)8462026/10/01 07:33:01 OK 20251218171726_add_pins.sql (26.94ms)8472026/10/01 07:33:01 OK 20241026095416_initial_model.sql (28.41ms)8482026/10/01 07:33:01 OK 20260905000000_add_claims.sql (22.29ms)8492026/10/01 07:33:01 OK 2_object_stats_trigger.sql (3.82ms)8502026/10/01 07:33:01 OK 1_commit_pending_closure.sql (5.37ms)8512026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (5.03ms)8522026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (8.91ms)8532026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (6.41ms)8542026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (6.36ms)8552026/10/01 07:33:01 OK 3_commit_push.sql (2.14ms)8562026/10/01 07:33:01 goose: up to current file version: 38572026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (6.17ms)8582026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (8.08ms)8592026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.54ms)8602026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3ms)8612026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200008622026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.33ms)8632026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200008642026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.59ms)8652026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200008662026/10/01 07:33:01 OK 3_commit_push.sql (1.82ms)8672026/10/01 07:33:01 goose: up to current file version: 38682026-10-01 07:33:01.782 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368692026-10-01 07:33:01.782 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.45ms)8712026/10/01 07:33:01 OK 20251218171726_add_pins.sql (5.98ms)8722026-10-01 07:33:01.783 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368732026-10-01 07:33:01.783 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8742026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.03ms)8752026-10-01 07:33:01.784 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368762026-10-01 07:33:01.784 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8772026-10-01 07:33:01.785 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368782026-10-01 07:33:01.785 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.95ms)8802026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.03ms)8812026/10/01 07:33:01 OK 20260905000000_add_claims.sql (5.12ms)8822026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.14ms)8832026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.05ms)8842026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.02ms)8852026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.05ms)8862026/10/01 07:33:01 OK 20241026095416_initial_model.sql (14.3ms)8872026/10/01 07:33:01 OK 20241026095416_initial_model.sql (15.01ms)8882026/10/01 07:33:01 OK 3_commit_push.sql (2.12ms)8892026/10/01 07:33:01 goose: up to current file version: 38902026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)8912026/10/01 07:33:01 OK 3_commit_push.sql (1.36ms)8922026/10/01 07:33:01 goose: up to current file version: 38932026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.67ms)8942026/10/01 07:33:01 OK 3_commit_push.sql (2.1ms)8952026/10/01 07:33:01 goose: up to current file version: 38962026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.43ms)8972026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200008982026/10/01 07:33:01 OK 20241026095416_initial_model.sql (17.16ms)8992026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)9002026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)9012026-10-01 07:33:01.791 UTC [469] ERROR: relation "goose_db_version" does not exist at character 369022026-10-01 07:33:01.791 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026/10/01 07:33:01 OK 20241026095416_initial_model.sql (13.12ms)9042026/10/01 07:33:01 OK 20241026095416_initial_model.sql (13.05ms)9052026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.92ms)9062026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009072026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.63ms)9082026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.03ms)9092026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)9102026/10/01 07:33:01 OK 20241026095416_initial_model.sql (12.97ms)9112026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)9122026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)9132026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.92ms)9142026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.7ms)9152026-10-01 07:33:01.795 UTC [471] ERROR: relation "goose_db_version" does not exist at character 369162026-10-01 07:33:01.795 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026-10-01 07:33:01.795 UTC [470] ERROR: relation "goose_db_version" does not exist at character 369182026-10-01 07:33:01.795 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.81ms)9202026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.86ms)9212026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.89ms)9222026-10-01 07:33:01.796 UTC [472] ERROR: relation "goose_db_version" does not exist at character 369232026-10-01 07:33:01.796 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)9252026/10/01 07:33:01 OK 3_commit_push.sql (2.59ms)9262026/10/01 07:33:01 goose: up to current file version: 39272026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.56ms)9282026-10-01 07:33:01.798 UTC [473] ERROR: relation "goose_db_version" does not exist at character 369292026-10-01 07:33:01.798 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9302026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.9ms)9312026/10/01 07:33:01 OK 20251218171726_add_pins.sql (5.46ms)9322026/10/01 07:33:01 OK 3_commit_push.sql (1.54ms)9332026/10/01 07:33:01 goose: up to current file version: 39342026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.46ms)9352026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009362026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.56ms)9372026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)9382026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.87ms)9392026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (6.05ms)9402026/10/01 07:33:01 OK 20241026095416_initial_model.sql (12.27ms)9412026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)9422026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)9432026/10/01 07:33:01 OK 1_commit_pending_closure.sql (4.15ms)9442026/10/01 07:33:01 OK 20241026095416_initial_model.sql (13.71ms)9452026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.84ms)9462026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)9472026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)9482026/10/01 07:33:01 OK 20241026095416_initial_model.sql (12.88ms)9492026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)9502026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.38ms)9512026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.65ms)9522026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)9532026/10/01 07:33:01 OK 20241026095416_initial_model.sql (12.61ms)9542026/10/01 07:33:01 OK 3_commit_push.sql (1.4ms)9552026/10/01 07:33:01 goose: up to current file version: 39562026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.65ms)9572026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.36ms)9582026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)9592026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.91ms)9602026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.92ms)9612026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.1ms)9622026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.58ms)9632026/10/01 07:33:01 OK 20260905000000_add_claims.sql (5.11ms)9642026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)9652026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.92ms)9662026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.04ms)9672026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009682026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.81ms)9692026/10/01 07:33:01 OK 20241026095416_initial_model.sql (12.43ms)9702026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.22ms)9712026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009722026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (4.07ms)9732026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)9742026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.77ms)9752026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.95ms)9762026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.74ms)9772026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.84ms)9782026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.03ms)9792026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009802026/10/01 07:33:01 OK 20241026095416_initial_model.sql (10.66ms)9812026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)9822026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.19ms)9832026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.86ms)9842026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009852026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.99ms)9862026/10/01 07:33:01 OK 20241026095416_initial_model.sql (11.42ms)9872026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.53ms)9882026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.25ms)9892026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009902026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.12ms)9912026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200009922026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)9932026/10/01 07:33:01 OK 20241026095416_initial_model.sql (12.15ms)9942026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.97ms)9952026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)9962026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.85ms)9972026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)9982026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)9992026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.77ms)10002026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.68ms)10012026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.43ms)10022026/10/01 07:33:01 OK 3_commit_push.sql (3.73ms)10032026/10/01 07:33:01 OK 20241026095416_initial_model.sql (15.12ms)10042026/10/01 07:33:01 goose: up to current file version: 310052026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.6ms)10062026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.53ms)10072026/10/01 07:33:01 OK 20251218171726_add_pins.sql (5.96ms)10082026/10/01 07:33:01 OK 3_commit_push.sql (1.71ms)10092026/10/01 07:33:01 goose: up to current file version: 310102026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.45ms)10112026/10/01 07:33:01 OK 2_object_stats_trigger.sql (3.29ms)10122026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.44ms)10132026-10-01 07:33:01.821 UTC [476] ERROR: relation "goose_db_version" does not exist at character 3610142026-10-01 07:33:01.821 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10152026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (4.33ms)10162026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (4.53ms)10172026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.24ms)10182026/10/01 07:33:01 OK 3_commit_push.sql (1.44ms)10192026/10/01 07:33:01 goose: up to current file version: 310202026/10/01 07:33:01 OK 3_commit_push.sql (1.69ms)10212026/10/01 07:33:01 goose: up to current file version: 310222026/10/01 07:33:01 OK 20260905000000_add_claims.sql (5.49ms)10232026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.89ms)10242026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.88ms)10252026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.86ms)10262026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)10272026/10/01 07:33:01 OK 3_commit_push.sql (1.74ms)10282026/10/01 07:33:01 goose: up to current file version: 310292026/10/01 07:33:01 OK 3_commit_push.sql (1.79ms)10302026/10/01 07:33:01 goose: up to current file version: 310312026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.89ms)10322026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010332026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.87ms)10342026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.83ms)10352026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)10362026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)10372026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.98ms)10382026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures10392026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.49ms)10402026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)10412026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.29ms)10422026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.34ms)10432026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010442026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.24ms)10452026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.03ms)10462026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.02ms)10472026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010482026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.2ms)10492026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)10502026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2ms)10512026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.2ms)10522026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.44ms)10532026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.95ms)10542026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010552026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.39ms)10562026/10/01 07:33:01 OK 1_commit_pending_closure.sql (1.81ms)10572026/10/01 07:33:01 OK 3_commit_push.sql (956.49µs)10582026/10/01 07:33:01 goose: up to current file version: 310592026/10/01 07:33:01 OK 2_object_stats_trigger.sql (995.91µs)10602026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.42ms)10612026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.05ms)10622026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.31ms)10632026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.24ms)10642026/10/01 07:33:01 OK 3_commit_push.sql (820.77µs)10652026/10/01 07:33:01 goose: up to current file version: 310662026/10/01 07:33:01 OK 1_commit_pending_closure.sql (1.9ms)10672026/10/01 07:33:01 OK 3_commit_push.sql (816.47µs)10682026/10/01 07:33:01 goose: up to current file version: 310692026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.22ms)10702026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.09ms)10712026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.08ms)10722026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.78ms)10732026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010742026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.7ms)10752026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010762026/10/01 07:33:01 OK 3_commit_push.sql (633.51µs)10772026/10/01 07:33:01 goose: up to current file version: 310782026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.63ms)10792026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010802026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.14ms)10812026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (1.87ms)10822026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.01ms)10832026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.29ms)10842026/10/01 07:33:01 OK 20241026095416_initial_model.sql (9.27ms)10852026/10/01 07:33:01 OK 1_commit_pending_closure.sql (1.89ms)10862026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.67ms)10872026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000010882026/10/01 07:33:01 OK 2_object_stats_trigger.sql (893.09µs)10892026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.5ms)10902026/10/01 07:33:01 OK 2_object_stats_trigger.sql (831.41µs)10912026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.19ms)10922026/10/01 07:33:01 OK 3_commit_push.sql (899.55µs)10932026/10/01 07:33:01 goose: up to current file version: 310942026/10/01 07:33:01 OK 3_commit_push.sql (899.83µs)10952026/10/01 07:33:01 goose: up to current file version: 310962026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)10972026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.05ms)10982026/10/01 07:33:01 OK 3_commit_push.sql (1.03ms)10992026/10/01 07:33:01 goose: up to current file version: 311002026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.58ms)11012026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000011022026/10/01 07:33:01 OK 2_object_stats_trigger.sql (781.35µs)11032026/10/01 07:33:01 OK 3_commit_push.sql (628.05µs)11042026/10/01 07:33:01 goose: up to current file version: 311052026/10/01 07:33:01 OK 1_commit_pending_closure.sql (1.44ms)11062026/10/01 07:33:01 OK 20251218171726_add_pins.sql (2.54ms)11072026/10/01 07:33:01 OK 2_object_stats_trigger.sql (816.03µs)11082026/10/01 07:33:01 OK 3_commit_push.sql (515.91µs)11092026/10/01 07:33:01 goose: up to current file version: 311102026/10/01 07:33:01 WARN readiness check failed error="closed pool"1111--- PASS: TestService_readinessHandler (0.29s)1112=== CONT TestService_ReadScope_PublicByDefault1113--- PASS: TestReadRedirectUsesPublicS3URL (0.29s)1114=== CONT TestClientIntegration11152026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)11162026/10/01 07:33:01 OK 20260905000000_add_claims.sql (3.78ms)11172026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.16ms)11182026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (1.59ms)11192026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000011202026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.08ms)11212026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.41ms)11222026/10/01 07:33:01 OK 3_commit_push.sql (975.73µs)11232026/10/01 07:33:01 goose: up to current file version: 311242026/10/01 07:33:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1125--- PASS: TestService_AuthMiddleware (0.31s)1126=== CONT TestClientErrorHandling1127=== RUN TestClientErrorHandling/InvalidStorePath1128=== PAUSE TestClientErrorHandling/InvalidStorePath1129=== RUN TestClientErrorHandling/InvalidAuthToken1130=== PAUSE TestClientErrorHandling/InvalidAuthToken1131=== RUN TestClientErrorHandling/ServerNotAvailable1132=== PAUSE TestClientErrorHandling/ServerNotAvailable1133=== CONT TestClientCADerivations11342026/10/01 07:33:01 INFO Aborted multipart uploads count=011352026/10/01 07:33:01 INFO Received cleanup request method=DELETE path=/api/pending_closures11362026/10/01 07:33:01 INFO Aborted multipart uploads count=011372026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures11382026/10/01 07:33:01 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=011392026/10/01 07:33:01 INFO Vacuumed table table=pending_closures1140=== NAME TestClientMultipleUploads1141 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1918575040/001/store/p99kj7c5sfvww3rl4vyfyjf6d7sa9fba-test-file-0.txt11422026/10/01 07:33:01 INFO Vacuumed table table=pending_objects11432026/10/01 07:33:01 INFO Vacuumed table table=multipart_uploads11442026/10/01 07:33:01 INFO Vacuumed table table=closures11452026/10/01 07:33:01 INFO Vacuumed table table=objects11462026/10/01 07:33:01 INFO Received cleanup request method=DELETE path=/api/pending_closures11472026/10/01 07:33:01 INFO Aborted multipart uploads count=111482026/10/01 07:33:01 INFO Aborted multipart uploads count=011492026/10/01 07:33:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11502026/10/01 07:33:01 WARN Force mode enabled - objects will be deleted immediately without grace period11512026-10-01 07:33:01.933 UTC [454] ERROR: Closure does not exist: id=111522026-10-01 07:33:01.933 UTC [454] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11532026-10-01 07:33:01.933 UTC [454] STATEMENT: -- name: CommitPendingClosure :exec1154 SELECT commit_pending_closure($1::bigint)1155 1156--- PASS: TestService_cleanupPendingClosuresHandler (0.38s)1157=== CONT TestCacheStatsHandler11582026/10/01 07:33:01 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=011592026-10-01 07:33:01.935 UTC [502] ERROR: relation "goose_db_version" does not exist at character 3611602026-10-01 07:33:01.935 UTC [502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11612026/10/01 07:33:01 INFO Vacuumed table table=pending_closures11622026-10-01 07:33:01.937 UTC [503] ERROR: relation "goose_db_version" does not exist at character 3611632026-10-01 07:33:01.937 UTC [503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11642026/10/01 07:33:01 INFO Vacuumed table table=pending_objects11652026/10/01 07:33:01 INFO Vacuumed table table=multipart_uploads11662026/10/01 07:33:01 INFO Vacuumed table table=closures11672026/10/01 07:33:01 INFO Vacuumed table table=objects1168--- PASS: TestPushDedupSurvivesConcurrentGC (0.40s)1169=== CONT TestCacheConfigHandler1170=== RUN TestCacheConfigHandler/full_config,_no_issuer1171=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1172=== RUN TestCacheConfigHandler/no_cache_url_configured1173=== PAUSE TestCacheConfigHandler/no_cache_url_configured1174=== RUN TestCacheConfigHandler/no_signing_keys1175=== PAUSE TestCacheConfigHandler/no_signing_keys1176=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1177=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1178=== CONT TestReadProxyNarinfoAlreadyDecompressed11792026-10-01 07:33:01.951 UTC [508] ERROR: relation "goose_db_version" does not exist at character 3611802026-10-01 07:33:01.951 UTC [508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11812026/10/01 07:33:01 OK 20241026095416_initial_model.sql (10.65ms)1182--- PASS: TestService_healthCheckHandler (0.40s)1183=== CONT TestReadProxyRangeRequest11842026/10/01 07:33:01 OK 20241026095416_initial_model.sql (10.95ms)11852026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)11862026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)11872026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.16ms)1188=== NAME TestClientMultipleUploads1189 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1918575040/001/store/27ifqapym3i22w8q970iwa0sjiqs4y6c-test-file-1.txt11902026/10/01 07:33:01 OK 20251218171726_add_pins.sql (3.72ms)11912026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)11922026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)11932026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.33ms)11942026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.03ms)11952026/10/01 07:33:01 OK 20241026095416_initial_model.sql (10.71ms)11962026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (2.79ms)11972026/10/01 07:33:01 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)11982026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.78ms)11992026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.81ms)12002026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000012012026/10/01 07:33:01 OK 20251218171726_add_pins.sql (4.35ms)12022026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures12032026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (3.82ms)12042026/10/01 07:33:01 goose: successfully migrated database to version: 202609231200001205=== NAME TestNARDeduplicationMetadataUploadBug1206 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug315512725/001/store/c5wcrz6y4az0rqf30rdghnib1y91wdrx-file1.txt12072026/10/01 07:33:01 OK 1_commit_pending_closure.sql (3.72ms)12082026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.46ms)12092026/10/01 07:33:01 OK 2_object_stats_trigger.sql (2.19ms)12102026/10/01 07:33:01 OK 2_object_stats_trigger.sql (1.49ms)12112026/10/01 07:33:01 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)12122026/10/01 07:33:01 OK 3_commit_push.sql (1.28ms)12132026/10/01 07:33:01 goose: up to current file version: 312142026/10/01 07:33:01 OK 3_commit_push.sql (1.54ms)12152026/10/01 07:33:01 goose: up to current file version: 312162026/10/01 07:33:01 OK 20260905000000_add_claims.sql (4.45ms)12172026/10/01 07:33:01 OK 20260920000000_drop_claims.sql (3.58ms)1218=== NAME TestClientMultipleUploads1219 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1918575040/001/store/nciyn533hj4pjf7ryjhn1fyfsxq6f0fn-test-file-2.txt12202026/10/01 07:33:01 OK 20260923120000_add_pushes.sql (2.85ms)12212026/10/01 07:33:01 goose: successfully migrated database to version: 2026092312000012222026/10/01 07:33:01 OK 1_commit_pending_closure.sql (2.82ms)12232026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures12242026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures12252026/10/01 07:33:01 INFO Received uploads request method=POST path=/api/pending_closures12262026/10/01 07:33:02 OK 2_object_stats_trigger.sql (7.7ms)12272026/10/01 07:33:02 OK 3_commit_push.sql (2.46ms)12282026/10/01 07:33:02 goose: up to current file version: 312292026/10/01 07:33:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12302026/10/01 07:33:02 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1231--- PASS: TestCompleteMultipartUnregistered (0.47s)1232=== CONT TestReadRedirectKeepsNarinfoProxied12332026-10-01 07:33:02.021 UTC [580] ERROR: relation "goose_db_version" does not exist at character 3612342026-10-01 07:33:02.021 UTC [580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026-10-01 07:33:02.029 UTC [600] ERROR: relation "goose_db_version" does not exist at character 3612362026-10-01 07:33:02.029 UTC [600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12372026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.97ms)12382026-10-01 07:33:02.041 UTC [603] ERROR: relation "goose_db_version" does not exist at character 3612392026-10-01 07:33:02.041 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)12412026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.93ms)12422026/10/01 07:33:02 OK 20241026095416_initial_model.sql (11.58ms)12432026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)12442026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)12452026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes12462026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.68ms)12472026/10/01 07:33:02 OK 20260905000000_add_claims.sql (6.02ms)12482026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.46ms)12492026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)12502026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.97ms)12512026/10/01 07:33:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12522026/10/01 07:33:02 INFO Uploading c5wcrz6y4az0rqf30rdghnib1y91wdrx-file1.txt (160B)12532026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes12542026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)12552026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.54ms)12562026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000012572026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.87ms)12582026/10/01 07:33:02 OK 1_commit_pending_closure.sql (3.01ms)12592026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.84ms)12602026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.63ms)12612026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.01ms)12622026/10/01 07:33:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12632026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12642026/10/01 07:33:02 INFO Uploading p99kj7c5sfvww3rl4vyfyjf6d7sa9fba-test-file-0.txt (160B)12652026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12662026/10/01 07:33:02 INFO Uploading nciyn533hj4pjf7ryjhn1fyfsxq6f0fn-test-file-2.txt (160B)12672026/10/01 07:33:02 INFO Uploading 27ifqapym3i22w8q970iwa0sjiqs4y6c-test-file-1.txt (160B)12682026/10/01 07:33:02 WARN Failed to register uploaded object key=c5wcrz6y4az0rqf30rdghnib1y91wdrx.ls error="server returned 404: 404 page not found\n"12692026/10/01 07:33:02 OK 3_commit_push.sql (2.31ms)12702026/10/01 07:33:02 goose: up to current file version: 312712026/10/01 07:33:02 INFO Signed narinfos id=1 count=112722026/10/01 07:33:02 INFO Uploading 1 narinfos12732026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (5.83ms)12742026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000012752026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (7.06ms)12762026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12772026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12782026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12792026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete12802026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.39ms)12812026/10/01 07:33:02 WARN Failed to register uploaded object key=c5wcrz6y4az0rqf30rdghnib1y91wdrx.narinfo error="server returned 404: 404 page not found\n"12822026/10/01 07:33:02 WARN Failed to register uploaded object key=p99kj7c5sfvww3rl4vyfyjf6d7sa9fba.ls error="server returned 404: 404 page not found\n"12832026/10/01 07:33:02 WARN Failed to register uploaded object key=27ifqapym3i22w8q970iwa0sjiqs4y6c.ls error="server returned 404: 404 page not found\n"12842026/10/01 07:33:02 WARN Failed to register uploaded object key=nciyn533hj4pjf7ryjhn1fyfsxq6f0fn.ls error="server returned 404: 404 page not found\n"12852026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12862026/10/01 07:33:02 INFO Signed narinfos id=1 count=312872026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.53ms)12882026/10/01 07:33:02 INFO Uploading 3 narinfos12892026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.33ms)12902026/10/01 07:33:02 OK 3_commit_push.sql (1.22ms)12912026/10/01 07:33:02 goose: up to current file version: 312922026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.52ms)12932026/10/01 07:33:02 INFO Upload complete. (69ms)12942026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (1.67ms)12952026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000012962026/10/01 07:33:02 WARN Failed to register uploaded object key=27ifqapym3i22w8q970iwa0sjiqs4y6c.narinfo error="server returned 404: 404 page not found\n"12972026/10/01 07:33:02 WARN Failed to register uploaded object key=nciyn533hj4pjf7ryjhn1fyfsxq6f0fn.narinfo error="server returned 404: 404 page not found\n"12982026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete12992026/10/01 07:33:02 WARN Failed to register uploaded object key=p99kj7c5sfvww3rl4vyfyjf6d7sa9fba.narinfo error="server returned 404: 404 page not found\n"1300=== NAME TestNARDeduplicationMetadataUploadBug1301 metadata_upload_test.go:54: Retrieved narinfo from S3:1302 StorePath: /build/TestNARDeduplicationMetadataUploadBug315512725/001/store/c5wcrz6y4az0rqf30rdghnib1y91wdrx-file1.txt1303 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1304 Compression: zstd1305 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1306 NarSize: 1601307 References: 1308 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13092026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.05ms)13102026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.42ms)13112026/10/01 07:33:02 OK 3_commit_push.sql (965.35µs)13122026/10/01 07:33:02 goose: up to current file version: 31313--- PASS: TestMetricsInventory (0.54s)1314=== CONT TestReadRedirectNar1315=== NAME TestNARDeduplicationMetadataUploadBug1316 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1317 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1318 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13192026/10/01 07:33:02 INFO Upload complete. (67ms)1320=== NAME TestClientMultipleUploads1321 client_integration_test.go:369: Uploaded 3 paths in 98.790251ms13222026-10-01 07:33:02.093 UTC [649] ERROR: relation "goose_db_version" does not exist at character 3613232026-10-01 07:33:02.093 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13242026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures1325--- PASS: TestClientMultipleUploads (0.55s)1326=== CONT TestReadProxyDisabled13272026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.23ms)13282026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)13292026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.46ms)13302026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)1331=== NAME TestNARDeduplicationMetadataUploadBug1332 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug315512725/001/store/y42994l4hpm0cxkvf2szvrvmhq2alwjl-file2.txt13332026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.86ms)13342026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.66ms)13352026/10/01 07:33:02 INFO Aborted multipart uploads count=013362026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.7ms)13372026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000013382026/10/01 07:33:02 WARN Force mode enabled - objects will be deleted immediately without grace period13392026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.74ms)13402026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.52ms)13412026/10/01 07:33:02 OK 3_commit_push.sql (1.17ms)13422026/10/01 07:33:02 goose: up to current file version: 313432026/10/01 07:33:02 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=013442026/10/01 07:33:02 INFO Vacuumed table table=pending_closures13452026/10/01 07:33:02 INFO Vacuumed table table=pending_objects13462026/10/01 07:33:02 INFO Vacuumed table table=multipart_uploads13472026/10/01 07:33:02 INFO Vacuumed table table=closures13482026/10/01 07:33:02 INFO Vacuumed table table=objects13492026/10/01 07:33:02 INFO lead: acquired remote=192.0.2.1:123413502026/10/01 07:33:02 INFO lead: released remote=192.0.2.1:12341351--- PASS: TestLeadEndsOnShutdown (0.59s)1352=== CONT TestReadProxyRootRedirectsToIndexHTML1353--- PASS: TestGCMetrics (0.59s)1354=== CONT TestReadProxyConditionalGet13552026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures13562026-10-01 07:33:02.163 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3613572026-10-01 07:33:02.163 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13582026/10/01 07:33:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13592026-10-01 07:33:02.172 UTC [696] ERROR: relation "goose_db_version" does not exist at character 3613602026-10-01 07:33:02.172 UTC [696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1361--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.63s)1362=== CONT TestReadProxyHead13632026/10/01 07:33:02 OK 20241026095416_initial_model.sql (12.34ms)13642026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)13652026/10/01 07:33:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13662026/10/01 07:33:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1367--- PASS: TestService_NativeMTLS (0.63s)1368=== CONT TestReadProxyInvalidPath13692026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.59ms)13702026/10/01 07:33:02 OK 20241026095416_initial_model.sql (11.29ms)13712026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes13722026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)13732026/10/01 07:33:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13742026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)13752026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.63ms)13762026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.63ms)13772026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)13782026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13792026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.74ms)13802026/10/01 07:33:02 INFO Signed narinfos id=2 count=113812026/10/01 07:33:02 WARN Failed to register uploaded object key=y42994l4hpm0cxkvf2szvrvmhq2alwjl.ls error="server returned 404: 404 page not found\n"13822026/10/01 07:33:02 INFO Uploading 1 narinfos13832026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.48ms)13842026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000013852026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.61ms)13862026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/2/complete13872026/10/01 07:33:02 WARN Failed to register uploaded object key=y42994l4hpm0cxkvf2szvrvmhq2alwjl.narinfo error="server returned 404: 404 page not found\n"13882026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.55ms)13892026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.38ms)13902026/10/01 07:33:02 INFO Upload complete. (51ms)13912026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.99ms)1392=== NAME TestNARDeduplicationMetadataUploadBug1393 metadata_upload_test.go:76: Retrieved narinfo from S3:1394 StorePath: /build/TestNARDeduplicationMetadataUploadBug315512725/001/store/y42994l4hpm0cxkvf2szvrvmhq2alwjl-file2.txt1395 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1396 Compression: zstd1397 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1398 NarSize: 1601399 References: 1400 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14012026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.41ms)14022026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000014032026/10/01 07:33:02 OK 3_commit_push.sql (1.73ms)14042026/10/01 07:33:02 goose: up to current file version: 31405 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1406 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):14072026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.53ms)1408 {"version":1,"root":{"type":"regular","size":44}}14092026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.73ms)1410--- PASS: TestNARDeduplicationMetadataUploadBug (0.67s)1411=== CONT TestReadProxy40414122026/10/01 07:33:02 OK 3_commit_push.sql (1.56ms)14132026/10/01 07:33:02 goose: up to current file version: 314142026-10-01 07:33:02.225 UTC [720] ERROR: relation "goose_db_version" does not exist at character 3614152026-10-01 07:33:02.225 UTC [720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14162026-10-01 07:33:02.226 UTC [721] ERROR: relation "goose_db_version" does not exist at character 3614172026-10-01 07:33:02.226 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14182026/10/01 07:33:02 OK 20241026095416_initial_model.sql (13.69ms)14192026/10/01 07:33:02 OK 20241026095416_initial_model.sql (13.77ms)14202026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)14212026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)14222026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.58ms)14232026/10/01 07:33:02 INFO lead: acquired remote=192.0.2.1:123414242026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.81ms)14252026-10-01 07:33:02.258 UTC [741] ERROR: relation "goose_db_version" does not exist at character 3614262026-10-01 07:33:02.258 UTC [741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14272026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)14282026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)14292026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.67ms)14302026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.37ms)14312026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.76ms)14322026-10-01 07:33:02.267 UTC [743] ERROR: relation "goose_db_version" does not exist at character 3614332026-10-01 07:33:02.267 UTC [743] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14342026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.25ms)14352026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000014362026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.2ms)14372026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.61ms)14382026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.71ms)14392026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000014402026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.32ms)1441--- PASS: TestGCBugBareHashReferences (0.72s)1442=== CONT TestReadProxyNarStreaming14432026/10/01 07:33:02 OK 3_commit_push.sql (1.19ms)14442026/10/01 07:33:02 goose: up to current file version: 314452026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.18ms)14462026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.25ms)14472026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.43ms)14482026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)14492026/10/01 07:33:02 OK 3_commit_push.sql (1.11ms)14502026/10/01 07:33:02 goose: up to current file version: 314512026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.27ms)14522026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)14532026/10/01 07:33:02 OK 20241026095416_initial_model.sql (11.07ms)14542026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)14552026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.35ms)14562026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.66ms)14572026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.2ms)14582026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.35ms)14592026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000014602026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)14612026/10/01 07:33:02 OK 1_commit_pending_closure.sql (3.17ms)14622026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.6ms)14632026/10/01 07:33:02 OK 3_commit_push.sql (1.64ms)14642026/10/01 07:33:02 goose: up to current file version: 314652026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.11ms)14662026-10-01 07:33:02.302 UTC [781] ERROR: relation "goose_db_version" does not exist at character 3614672026-10-01 07:33:02.302 UTC [781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14682026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.12ms)14692026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (3.08ms)14702026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000014712026/10/01 07:33:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14722026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.58ms)14732026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.88ms)14742026/10/01 07:33:02 OK 3_commit_push.sql (1.82ms)14752026/10/01 07:33:02 goose: up to current file version: 314762026/10/01 07:33:02 OK 20241026095416_initial_model.sql (11.4ms)14772026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)14782026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.36ms)14792026/10/01 07:33:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14802026/10/01 07:33:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGU2YjZjMGEtMThhMy00ZWVkLWJkOTQtZTY0NjQ0N2RhMDIzLjFjOTgxMzFmLTg0ZTEtNDEzMi05Yjc3LTdjNzc2NmFmZGEwOHgxNzkwODM5OTgxOTg0MDY3MTQ2 parts=1014812026/10/01 07:33:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14822026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)14832026/10/01 07:33:02 INFO Completed upload id=114842026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures14852026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.01ms)14862026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures14872026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (1.99ms)14882026/10/01 07:33:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14892026/10/01 07:33:02 WARN Found objects in DB but missing from S3, will re-upload count=114902026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (1.66ms)14912026/10/01 07:33:02 goose: successfully migrated database to version: 202609231200001492--- PASS: TestService_verifyS3Integrity (0.78s)1493=== CONT TestCreatePin_ReservedPins14942026/10/01 07:33:02 OK 1_commit_pending_closure.sql (1.76ms)14952026/10/01 07:33:02 OK 2_object_stats_trigger.sql (899.17µs)14962026/10/01 07:33:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGU2YjZjMGEtMThhMy00ZWVkLWJkOTQtZTY0NjQ0N2RhMDIzLjg5OGE5ZTI3LWZjZmUtNDQwZC05NWZiLWNmNTkyNTZmNjIwZXgxNzkwODM5OTgyMDA1OTg5MTM1 parts=1014972026/10/01 07:33:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14982026/10/01 07:33:02 OK 3_commit_push.sql (590.05µs)14992026/10/01 07:33:02 goose: up to current file version: 315002026-10-01 07:33:02.340 UTC [853] ERROR: relation "goose_db_version" does not exist at character 3615012026-10-01 07:33:02.340 UTC [853] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15022026/10/01 07:33:02 INFO Completed upload id=115032026/10/01 07:33:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015042026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/01 07:33:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures1506=== NAME TestPinProtectsFromGC1507 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2294836780/001/store/x1n0m7dvbcxyafdv9pc9q7jppp1p7l5y-pinned-file.txt1508 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2294836780/001/store/5xhk6mgzr8hd182d7cmf7y5fvqjhb79x-unpinned-file.txt1509--- PASS: TestService_ReadScope_PublicByDefault (0.51s)1510=== CONT TestReadProxyNarinfo15112026/10/01 07:33:02 INFO Aborted multipart uploads count=015122026/10/01 07:33:02 OK 20241026095416_initial_model.sql (9.19ms)15132026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)15142026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.28ms)15152026/10/01 07:33:02 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=015162026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)15172026/10/01 07:33:02 INFO Vacuumed table table=pending_closures15182026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.58ms)15192026/10/01 07:33:02 INFO Vacuumed table table=pending_objects15202026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.41ms)15212026/10/01 07:33:02 INFO Vacuumed table table=multipart_uploads15222026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.64ms)15232026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000015242026/10/01 07:33:02 INFO Vacuumed table table=closures15252026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.21ms)15262026/10/01 07:33:02 INFO Vacuumed table table=objects15272026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.8ms)15282026/10/01 07:33:02 OK 3_commit_push.sql (1.63ms)15292026/10/01 07:33:02 goose: up to current file version: 315302026/10/01 07:33:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001531--- PASS: TestService_createPendingClosureHandler (0.84s)1532=== CONT TestIsValidCachePath1533=== RUN TestIsValidCachePath/narinfo1534=== PAUSE TestIsValidCachePath/narinfo1535=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1536=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1537=== RUN TestIsValidCachePath/nar_zst1538=== PAUSE TestIsValidCachePath/nar_zst1539=== RUN TestIsValidCachePath/nar_xz1540=== PAUSE TestIsValidCachePath/nar_xz1541=== RUN TestIsValidCachePath/nar_bz21542=== PAUSE TestIsValidCachePath/nar_bz21543=== RUN TestIsValidCachePath/nar_uncompressed1544=== PAUSE TestIsValidCachePath/nar_uncompressed1545=== RUN TestIsValidCachePath/ls1546=== PAUSE TestIsValidCachePath/ls1547=== RUN TestIsValidCachePath/log1548=== PAUSE TestIsValidCachePath/log1549=== RUN TestIsValidCachePath/realisation1550=== PAUSE TestIsValidCachePath/realisation1551=== RUN TestIsValidCachePath/nix-cache-info1552=== PAUSE TestIsValidCachePath/nix-cache-info1553=== RUN TestIsValidCachePath/index.html1554=== PAUSE TestIsValidCachePath/index.html1555=== RUN TestIsValidCachePath/traversal_parent1556=== PAUSE TestIsValidCachePath/traversal_parent1557=== RUN TestIsValidCachePath/traversal_in_middle1558=== PAUSE TestIsValidCachePath/traversal_in_middle1559=== RUN TestIsValidCachePath/invalid_char_e1560=== PAUSE TestIsValidCachePath/invalid_char_e1561=== RUN TestIsValidCachePath/invalid_char_u1562=== PAUSE TestIsValidCachePath/invalid_char_u1563=== RUN TestIsValidCachePath/random_path1564=== PAUSE TestIsValidCachePath/random_path1565=== RUN TestIsValidCachePath/empty1566=== PAUSE TestIsValidCachePath/empty1567=== RUN TestIsValidCachePath/leading_slash1568=== PAUSE TestIsValidCachePath/leading_slash1569=== RUN TestIsValidCachePath/wrong_extension1570=== PAUSE TestIsValidCachePath/wrong_extension1571=== RUN TestIsValidCachePath/short_hash1572=== PAUSE TestIsValidCachePath/short_hash1573=== CONT TestProxyHeadersOnlyTrustedOnSocket15742026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures15752026/10/01 07:33:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46073/oidc15762026/10/01 07:33:02 INFO lead: released remote=192.0.2.1:123415772026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures15782026/10/01 07:33:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15792026/10/01 07:33:02 INFO Uploading yfh1agdki9z5jpv27kr9hsz12i9w0by5-a (216B)15802026/10/01 07:33:02 INFO Uploading y1zxkcl3kfrvafmyf8q00g7540l2j6mw-shared-dep (136B)1581=== NAME TestClientWithDependencies1582 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3745204929/001/store/r87616w49gjkmcvnz3fqh2j0apxd445s-test-script1583=== NAME TestClientIntegration1584 client_integration_test.go:286: Created store path: /build/TestClientIntegration3003981235/002/store/792j818pm6lpdkincv6x6lp3fjwxwd38-test-file.txt15852026/10/01 07:33:02 WARN Failed to register uploaded object key=yfh1agdki9z5jpv27kr9hsz12i9w0by5.ls error="server returned 404: 404 page not found\n"15862026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15872026/10/01 07:33:02 WARN Failed to register uploaded object key=y1zxkcl3kfrvafmyf8q00g7540l2j6mw.ls error="server returned 404: 404 page not found\n"15882026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1cs7ghgf8c3aqbwbfvkzz8hian7wip2asck7ahniqvi05c310sk6.nar.zst error="server returned 404: 404 page not found\n"15892026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15902026/10/01 07:33:02 WARN Failed to register uploaded object key=17151i3yr1p74ymhbrax7k4qd3g49cks.ls error="server returned 404: 404 page not found\n"15912026/10/01 07:33:02 INFO Signed narinfos id=1 count=215922026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15932026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes15942026/10/01 07:33:02 INFO Signed narinfos id=2 count=215952026/10/01 07:33:02 INFO Uploading 4 narinfos15962026-10-01 07:33:02.426 UTC [1075] ERROR: relation "goose_db_version" does not exist at character 3615972026-10-01 07:33:02.426 UTC [1075] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15982026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes15992026/10/01 07:33:02 WARN Failed to register uploaded object key=y1zxkcl3kfrvafmyf8q00g7540l2j6mw.narinfo error="server returned 404: 404 page not found\n"16002026/10/01 07:33:02 WARN Failed to register uploaded object key=yfh1agdki9z5jpv27kr9hsz12i9w0by5.narinfo error="server returned 404: 404 page not found\n"16012026/10/01 07:33:02 WARN Failed to register uploaded object key=17151i3yr1p74ymhbrax7k4qd3g49cks.narinfo error="server returned 404: 404 page not found\n"16022026/10/01 07:33:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16032026/10/01 07:33:02 INFO Uploading aqllrmdlk4snx4pi42h208kywgqynkzn-shared-dep (136B)16042026/10/01 07:33:02 INFO Uploading n7vkk459a01fygc6vncrk7nxi9bkmhj2-b (216B)16052026/10/01 07:33:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16062026/10/01 07:33:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16072026/10/01 07:33:02 INFO Uploading x1n0m7dvbcxyafdv9pc9q7jppp1p7l5y-pinned-file.txt (128B)16082026/10/01 07:33:02 WARN Failed to register uploaded object key=y1zxkcl3kfrvafmyf8q00g7540l2j6mw.narinfo error="server returned 404: 404 page not found\n"1609--- PASS: TestCacheStatsHandler (0.50s)1610=== CONT TestParseSingleRange1611=== RUN TestParseSingleRange/none1612=== PAUSE TestParseSingleRange/none1613=== RUN TestParseSingleRange/unknown_unit1614=== PAUSE TestParseSingleRange/unknown_unit1615=== RUN TestParseSingleRange/multi-range_ignored1616=== PAUSE TestParseSingleRange/multi-range_ignored1617=== RUN TestParseSingleRange/malformed_no_dash1618=== PAUSE TestParseSingleRange/malformed_no_dash1619=== RUN TestParseSingleRange/malformed_both_empty1620=== PAUSE TestParseSingleRange/malformed_both_empty1621=== RUN TestParseSingleRange/malformed_end_before_start1622=== PAUSE TestParseSingleRange/malformed_end_before_start1623=== RUN TestParseSingleRange/closed16242026/10/01 07:33:02 WARN Failed to register uploaded object key=vcbxbb1ci8nbwm42k365qwi07s344sas.ls error="server returned 404: 404 page not found\n"1625=== PAUSE TestParseSingleRange/closed1626=== RUN TestParseSingleRange/open-ended1627=== PAUSE TestParseSingleRange/open-ended1628=== RUN TestParseSingleRange/end_clamped_to_size1629=== PAUSE TestParseSingleRange/end_clamped_to_size1630=== RUN TestParseSingleRange/suffix1631=== PAUSE TestParseSingleRange/suffix1632=== RUN TestParseSingleRange/suffix_exceeds_size1633=== PAUSE TestParseSingleRange/suffix_exceeds_size1634=== RUN TestParseSingleRange/single_byte1635=== PAUSE TestParseSingleRange/single_byte1636=== RUN TestParseSingleRange/start_past_EOF16372026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1638=== PAUSE TestParseSingleRange/start_past_EOF16392026/10/01 07:33:02 WARN Failed to register uploaded object key=n7vkk459a01fygc6vncrk7nxi9bkmhj2.ls error="server returned 404: 404 page not found\n"1640=== RUN TestParseSingleRange/start_far_past_EOF16412026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1642=== PAUSE TestParseSingleRange/start_far_past_EOF1643=== CONT TestRedundantMultipartUpload16442026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/0qz3r206vq8cbd4lpk3chxnb15al92hjvx4w4n6201gxakp4f1q7.nar.zst error="server returned 404: 404 page not found\n"16452026/10/01 07:33:02 WARN Failed to register uploaded object key=aqllrmdlk4snx4pi42h208kywgqynkzn.ls error="server returned 404: 404 page not found\n"16462026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16472026/10/01 07:33:02 WARN Failed to register uploaded object key=x1n0m7dvbcxyafdv9pc9q7jppp1p7l5y.ls error="server returned 404: 404 page not found\n"16482026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16492026/10/01 07:33:02 INFO Signed narinfos id=1 count=316502026/10/01 07:33:02 INFO Uploading 3 narinfos16512026/10/01 07:33:02 INFO Signed narinfos id=1 count=116522026/10/01 07:33:02 INFO Uploading 1 narinfos16532026/10/01 07:33:02 INFO Completed upload id=116542026/10/01 07:33:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16552026/10/01 07:33:02 INFO Completed upload id=216562026/10/01 07:33:02 INFO Upload complete. (80ms)16572026/10/01 07:33:02 WARN Failed to register uploaded object key=vcbxbb1ci8nbwm42k365qwi07s344sas.narinfo error="server returned 404: 404 page not found\n"16582026/10/01 07:33:02 OK 20241026095416_initial_model.sql (9.94ms)16592026/10/01 07:33:02 WARN Failed to register uploaded object key=aqllrmdlk4snx4pi42h208kywgqynkzn.narinfo error="server returned 404: 404 page not found\n"16602026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete16612026/10/01 07:33:02 WARN Failed to register uploaded object key=n7vkk459a01fygc6vncrk7nxi9bkmhj2.narinfo error="server returned 404: 404 page not found\n"16622026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete16632026/10/01 07:33:02 WARN Failed to register uploaded object key=x1n0m7dvbcxyafdv9pc9q7jppp1p7l5y.narinfo error="server returned 404: 404 page not found\n"1664=== NAME TestClientFallsBackToClosures1665 client_pushes_test.go:112: Retrieved narinfo from S3:1666 StorePath: /build/TestClientFallsBackToClosures1448070678/001/store/y1zxkcl3kfrvafmyf8q00g7540l2j6mw-shared-dep1667 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1668 Compression: zstd1669 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821670 NarSize: 1361671 References: 1672 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16732026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)1674 client_pushes_test.go:112: Retrieved narinfo from S3:1675 StorePath: /build/TestClientFallsBackToClosures1448070678/001/store/yfh1agdki9z5jpv27kr9hsz12i9w0by5-a1676 URL: nar/1cs7ghgf8c3aqbwbfvkzz8hian7wip2asck7ahniqvi05c310sk6.nar.zst1677 Compression: zstd1678 NarHash: sha256:1cs7ghgf8c3aqbwbfvkzz8hian7wip2asck7ahniqvi05c310sk61679 NarSize: 2161680 References: /build/TestClientFallsBackToClosures1448070678/001/store/y1zxkcl3kfrvafmyf8q00g7540l2j6mw-shared-dep1681 CA: text:sha256:1lynm7nigd136dawycwrc2g8m5kaxywmj1di612py284fdkajj2216822026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.35ms)1683=== NAME TestClientWithDependencies1684 client_integration_test.go:615: Found 1 dependencies (including self)1685=== NAME TestClientFallsBackToClosures16862026/10/01 07:33:02 INFO Upload complete. (64ms)1687 client_pushes_test.go:112: Retrieved narinfo from S3:1688 StorePath: /build/TestClientFallsBackToClosures1448070678/001/store/17151i3yr1p74ymhbrax7k4qd3g49cks-b1689 URL: nar/1cs7ghgf8c3aqbwbfvkzz8hian7wip2asck7ahniqvi05c310sk6.nar.zst1690 Compression: zstd1691 NarHash: sha256:1cs7ghgf8c3aqbwbfvkzz8hian7wip2asck7ahniqvi05c310sk61692 NarSize: 2161693 References: /build/TestClientFallsBackToClosures1448070678/001/store/y1zxkcl3kfrvafmyf8q00g7540l2j6mw-shared-dep1694 CA: text:sha256:1lynm7nigd136dawycwrc2g8m5kaxywmj1di612py284fdkajj2216952026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes16962026/10/01 07:33:02 INFO Upload complete. (63ms)1697=== NAME TestClientPushesUseOnePush1698 client_pushes_test.go:97: Retrieved narinfo from S3:1699 StorePath: /build/TestClientPushesUseOnePush3354330234/001/store/aqllrmdlk4snx4pi42h208kywgqynkzn-shared-dep1700 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1701 Compression: zstd1702 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821703 NarSize: 1361704 References: 1705 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17062026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)1707--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.51s)1708=== CONT TestParseSize1709--- PASS: TestParseSize (0.00s)1710=== CONT TestService_Rustfstest1711--- PASS: TestClientFallsBackToClosures (0.84s)1712=== CONT TestPresignedUploadRegisteredBeforeCommit17132026/10/01 07:33:02 INFO lead: acquired remote=192.0.2.1:12341714=== NAME TestClientPushesUseOnePush1715 client_pushes_test.go:97: Retrieved narinfo from S3:1716 StorePath: /build/TestClientPushesUseOnePush3354330234/001/store/vcbxbb1ci8nbwm42k365qwi07s344sas-a1717 URL: nar/0qz3r206vq8cbd4lpk3chxnb15al92hjvx4w4n6201gxakp4f1q7.nar.zst1718 Compression: zstd1719 NarHash: sha256:0qz3r206vq8cbd4lpk3chxnb15al92hjvx4w4n6201gxakp4f1q71720 NarSize: 2161721 References: /build/TestClientPushesUseOnePush3354330234/001/store/aqllrmdlk4snx4pi42h208kywgqynkzn-shared-dep1722 CA: text:sha256:1i1b17iwap93i7bli1y2p4qridr4zp2yw7lzg5vq1iiixly20irz17232026/10/01 07:33:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17242026/10/01 07:33:02 INFO Uploading 41vccqxjbcya3b5pa3x0k9jx0f53hv9p-shared-dep (136B)17252026/10/01 07:33:02 INFO Uploading byz3n293jhc2ksbbi238ggxx0vsqyx8m-top (224B)17262026/10/01 07:33:02 OK 20260905000000_add_claims.sql (5.82ms)1727 client_pushes_test.go:97: Retrieved narinfo from S3:1728 StorePath: /build/TestClientPushesUseOnePush3354330234/001/store/n7vkk459a01fygc6vncrk7nxi9bkmhj2-b1729 URL: nar/0qz3r206vq8cbd4lpk3chxnb15al92hjvx4w4n6201gxakp4f1q7.nar.zst1730 Compression: zstd1731 NarHash: sha256:0qz3r206vq8cbd4lpk3chxnb15al92hjvx4w4n6201gxakp4f1q71732 NarSize: 2161733 References: /build/TestClientPushesUseOnePush3354330234/001/store/aqllrmdlk4snx4pi42h208kywgqynkzn-shared-dep1734 CA: text:sha256:1i1b17iwap93i7bli1y2p4qridr4zp2yw7lzg5vq1iiixly20irz17352026/10/01 07:33:02 INFO lead: released remote=192.0.2.1:12341736--- PASS: TestLeadElectsOneAndHandsOver (0.85s)1737=== CONT TestCompletedNarNotReofferedAcrossClosures17382026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.06ms)17392026/10/01 07:33:02 WARN Failed to register uploaded object key=byz3n293jhc2ksbbi238ggxx0vsqyx8m.ls error="server returned 404: 404 page not found\n"17402026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/0ln0vcckcc1gkfb2nr4k4m1m618h0k5hy9lx2j5d4k5677lxvkv5.nar.zst error="server returned 404: 404 page not found\n"17412026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17422026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17432026/10/01 07:33:02 WARN Failed to register uploaded object key=41vccqxjbcya3b5pa3x0k9jx0f53hv9p.ls error="server returned 404: 404 page not found\n"17442026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.95ms)17452026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000017462026/10/01 07:33:02 INFO Signed narinfos id=1 count=217472026/10/01 07:33:02 INFO Uploading 2 narinfos1748--- PASS: TestClientPushesUseOnePush (0.85s)1749=== CONT TestCompleteMultipartUpload_ErrorButObjectExists17502026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.43ms)17512026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.31ms)17522026/10/01 07:33:02 WARN Failed to register uploaded object key=byz3n293jhc2ksbbi238ggxx0vsqyx8m.narinfo error="server returned 404: 404 page not found\n"17532026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17542026/10/01 07:33:02 WARN Failed to register uploaded object key=41vccqxjbcya3b5pa3x0k9jx0f53hv9p.narinfo error="server returned 404: 404 page not found\n"17552026/10/01 07:33:02 OK 3_commit_push.sql (1.65ms)17562026/10/01 07:33:02 goose: up to current file version: 317572026/10/01 07:33:02 INFO Upload complete. (65ms)1758=== NAME TestClientSharedPathCommittedMidPush1759 client_integration_test.go:680: Retrieved narinfo from S3:1760 StorePath: /build/TestClientSharedPathCommittedMidPush1156966539/001/store/41vccqxjbcya3b5pa3x0k9jx0f53hv9p-shared-dep1761 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1762 Compression: zstd1763 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821764 NarSize: 1361765 References: 1766 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1767=== NAME TestClientCADerivations1768 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1248607798/001/store/v570j1rqxz68yw6hjan29mvnrbhdlk7f-ca-test1769=== NAME TestClientSharedPathCommittedMidPush1770 client_integration_test.go:680: Retrieved narinfo from S3:1771 StorePath: /build/TestClientSharedPathCommittedMidPush1156966539/001/store/byz3n293jhc2ksbbi238ggxx0vsqyx8m-top1772 URL: nar/0ln0vcckcc1gkfb2nr4k4m1m618h0k5hy9lx2j5d4k5677lxvkv5.nar.zst1773 Compression: zstd1774 NarHash: sha256:0ln0vcckcc1gkfb2nr4k4m1m618h0k5hy9lx2j5d4k5677lxvkv51775 NarSize: 2241776 References: /build/TestClientSharedPathCommittedMidPush1156966539/001/store/41vccqxjbcya3b5pa3x0k9jx0f53hv9p-shared-dep1777 CA: text:sha256:15n04lb9jag9c2xrgv6vny8axky0a375c18d90m2n0isxaia5jdl17782026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes1779--- PASS: TestReadProxyRangeRequest (0.53s)1780=== CONT TestGCTaskStore_DeduplicateSameParams1781--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1782=== CONT TestGCTaskStore_Fail1783--- PASS: TestGCTaskStore_Fail (0.00s)1784=== CONT TestGCTaskStore_PhaseUpdates1785--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1786=== CONT TestGCTaskStore_CompletedAllowsNewTask1787--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1788=== CONT TestGCTaskStore_GetReturnsLatest1789--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1790=== CONT TestGCTaskStore_GetEmpty1791--- PASS: TestGCTaskStore_GetEmpty (0.00s)1792=== CONT TestGCTaskStore_ConflictDifferentParams1793--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1794=== CONT TestGCSweepDeliversEachKeyOnce1795--- PASS: TestClientSharedPathCommittedMidPush (0.87s)1796=== CONT TestGCTaskStore_StartNew1797--- PASS: TestGCTaskStore_StartNew (0.00s)1798=== CONT TestFailedS3DeleteKeepsTombstone17992026-10-01 07:33:02.491 UTC [1263] ERROR: relation "goose_db_version" does not exist at character 3618002026-10-01 07:33:02.491 UTC [1263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18012026-10-01 07:33:02.492 UTC [1262] ERROR: relation "goose_db_version" does not exist at character 3618022026-10-01 07:33:02.492 UTC [1262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18032026/10/01 07:33:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18042026/10/01 07:33:02 INFO Uploading 792j818pm6lpdkincv6x6lp3fjwxwd38-test-file.txt (152B)18052026/10/01 07:33:02 WARN Failed to register uploaded object key=792j818pm6lpdkincv6x6lp3fjwxwd38.ls error="server returned 404: 404 page not found\n"18062026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18072026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18082026/10/01 07:33:02 INFO Signed narinfos id=1 count=118092026/10/01 07:33:02 INFO Uploading 1 narinfos18102026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes18112026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes18122026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete18132026/10/01 07:33:02 WARN Failed to register uploaded object key=792j818pm6lpdkincv6x6lp3fjwxwd38.narinfo error="server returned 404: 404 page not found\n"1814--- PASS: TestReadRedirectKeepsNarinfoProxied (0.50s)1815=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1816=== NAME TestClientCADerivations1817 client_ca_test.go:139: Found 1 dependencies (including self)18182026/10/01 07:33:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18192026/10/01 07:33:02 INFO Uploading 5xhk6mgzr8hd182d7cmf7y5fvqjhb79x-unpinned-file.txt (128B)18202026/10/01 07:33:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18212026/10/01 07:33:02 INFO Uploading r87616w49gjkmcvnz3fqh2j0apxd445s-test-script (136B)18222026/10/01 07:33:02 OK 20241026095416_initial_model.sql (14.23ms)18232026/10/01 07:33:02 OK 20241026095416_initial_model.sql (16.27ms)18242026/10/01 07:33:02 INFO Upload complete. (75ms)18252026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18262026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)18272026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18282026/10/01 07:33:02 WARN Failed to register uploaded object key=5xhk6mgzr8hd182d7cmf7y5fvqjhb79x.ls error="server returned 404: 404 page not found\n"18292026/10/01 07:33:02 INFO Signed narinfos id=2 count=118302026/10/01 07:33:02 INFO Uploading 1 narinfos18312026/10/01 07:33:02 WARN Failed to register uploaded object key=log/fnrqijscsdxaj6iavl7dkdbwsk09ynsy-test-script.drv error="server returned 404: 404 page not found\n"18322026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)18332026/10/01 07:33:02 WARN Failed to register uploaded object key=r87616w49gjkmcvnz3fqh2j0apxd445s.ls error="server returned 404: 404 page not found\n"18342026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18352026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18362026/10/01 07:33:02 INFO Signed narinfos id=1 count=118372026/10/01 07:33:02 INFO Uploading 1 narinfos18382026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.52ms)18392026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.63ms)18402026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/2/complete18412026/10/01 07:33:02 WARN Failed to register uploaded object key=5xhk6mgzr8hd182d7cmf7y5fvqjhb79x.narinfo error="server returned 404: 404 page not found\n"18422026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete18432026/10/01 07:33:02 WARN Failed to register uploaded object key=r87616w49gjkmcvnz3fqh2j0apxd445s.narinfo error="server returned 404: 404 page not found\n"18442026-10-01 07:33:02.536 UTC [1323] ERROR: relation "goose_db_version" does not exist at character 3618452026-10-01 07:33:02.536 UTC [1323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18462026/10/01 07:33:02 INFO Upload complete. (62ms)18472026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (11.97ms)18482026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (13.44ms)18492026/10/01 07:33:02 INFO Upload complete. (66ms)1850=== NAME TestClientWithDependencies1851 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3745204929/001/store) requires matching store prefix18522026/10/01 07:33:02 OK 20260905000000_add_claims.sql (5.52ms)18532026/10/01 07:33:02 OK 20260905000000_add_claims.sql (6.9ms)1854--- PASS: TestClientWithDependencies (0.85s)1855=== CONT TestObjectStatsTrigger1856--- PASS: TestReadRedirectNar (0.47s)1857=== CONT TestOrphanedObjectsGCStressTest18582026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (4.07ms)18592026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.55ms)18602026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (3.88ms)18612026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000018622026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (4.89ms)18632026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000018642026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.81ms)18652026/10/01 07:33:02 OK 1_commit_pending_closure.sql (3.14ms)18662026-10-01 07:33:02.563 UTC [1345] ERROR: relation "goose_db_version" does not exist at character 3618672026-10-01 07:33:02.563 UTC [1345] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18682026-10-01 07:33:02.563 UTC [1347] ERROR: relation "goose_db_version" does not exist at character 3618692026-10-01 07:33:02.563 UTC [1347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18702026/10/01 07:33:02 OK 20241026095416_initial_model.sql (16.06ms)18712026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.68ms)18722026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.07ms)18732026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)18742026/10/01 07:33:02 OK 3_commit_push.sql (2.88ms)18752026/10/01 07:33:02 goose: up to current file version: 318762026/10/01 07:33:02 OK 3_commit_push.sql (2.79ms)18772026/10/01 07:33:02 goose: up to current file version: 318782026/10/01 07:33:02 INFO All 1 paths already cached1879=== NAME TestClientIntegration1880 client_integration_test.go:312: Retrieved narinfo from S3:1881 StorePath: /build/TestClientIntegration3003981235/002/store/792j818pm6lpdkincv6x6lp3fjwxwd38-test-file.txt1882 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1883 Compression: zstd1884 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11885 NarSize: 1521886 References: 1887 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11888--- PASS: TestReadProxyDisabled (0.47s)1889=== CONT TestOrphanedObjectsGC18902026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.01ms)18912026-10-01 07:33:02.573 UTC [1366] ERROR: relation "goose_db_version" does not exist at character 3618922026-10-01 07:33:02.573 UTC [1366] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1893=== NAME TestClientIntegration1894 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1895 client_integration_test.go:313: Decompressed .ls content (64 bytes):1896 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1897 client_integration_test.go:316: Testing garbage collection...18982026/10/01 07:33:02 INFO Received create pin request method=POST path=/api/pins/myapp18992026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)19002026-10-01 07:33:02.579 UTC [1385] ERROR: relation "goose_db_version" does not exist at character 3619012026-10-01 07:33:02.579 UTC [1385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19022026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.57ms)19032026/10/01 07:33:02 OK 20241026095416_initial_model.sql (12.46ms)19042026/10/01 07:33:02 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2294836780/001/store/x1n0m7dvbcxyafdv9pc9q7jppp1p7l5y-pinned-file.txt narinfo_key=x1n0m7dvbcxyafdv9pc9q7jppp1p7l5y.narinfo19052026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.74ms)19062026/10/01 07:33:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures19072026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)19082026/10/01 07:33:02 INFO Garbage collection started19092026-10-01 07:33:02.587 UTC [1389] ERROR: relation "goose_db_version" does not exist at character 3619102026-10-01 07:33:02.587 UTC [1389] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19112026-10-01 07:33:02.588 UTC [1388] ERROR: relation "goose_db_version" does not exist at character 3619122026-10-01 07:33:02.588 UTC [1388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19132026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (8.25ms)19142026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019152026/10/01 07:33:02 OK 20241026095416_initial_model.sql (21.55ms)19162026/10/01 07:33:02 OK 20251218171726_add_pins.sql (7.88ms)19172026/10/01 07:33:02 OK 20241026095416_initial_model.sql (13.25ms)19182026/10/01 07:33:02 INFO Aborted multipart uploads count=019192026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)19202026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.94ms)19212026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)19222026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)19232026/10/01 07:33:02 OK 2_object_stats_trigger.sql (3.68ms)19242026/10/01 07:33:02 WARN Force mode enabled - objects will be deleted immediately without grace period19252026/10/01 07:33:02 OK 3_commit_push.sql (1.94ms)19262026/10/01 07:33:02 goose: up to current file version: 319272026/10/01 07:33:02 OK 20251218171726_add_pins.sql (6.22ms)19282026/10/01 07:33:02 OK 20251218171726_add_pins.sql (6.04ms)19292026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.39ms)19302026/10/01 07:33:02 OK 20241026095416_initial_model.sql (13.91ms)19312026-10-01 07:33:02.607 UTC [1410] ERROR: relation "goose_db_version" does not exist at character 3619322026-10-01 07:33:02.607 UTC [1410] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1933--- PASS: TestReadProxyConditionalGet (0.46s)1934=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit19352026/10/01 07:33:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures19362026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (4.25ms)19372026/10/01 07:33:02 INFO Garbage collection started19382026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)19392026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.83ms)19402026/10/01 07:33:02 OK 20241026095416_initial_model.sql (13.48ms)19412026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)19422026/10/01 07:33:02 OK 20241026095416_initial_model.sql (14.92ms)19432026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (3.4ms)19442026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019452026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)19462026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)19472026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.64ms)19482026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.51ms)19492026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.2ms)19502026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.53ms)19512026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.32ms)19522026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.39ms)19532026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.42ms)19542026/10/01 07:33:02 INFO Aborted multipart uploads count=019552026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.19ms)19562026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.3ms)19572026/10/01 07:33:02 OK 3_commit_push.sql (1.75ms)19582026/10/01 07:33:02 goose: up to current file version: 319592026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)19602026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.74ms)19612026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019622026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (3.77ms)19632026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019642026/10/01 07:33:02 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=019652026/10/01 07:33:02 WARN Force mode enabled - objects will be deleted immediately without grace period19662026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.68ms)19672026/10/01 07:33:02 OK 1_commit_pending_closure.sql (3.43ms)19682026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)19692026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.61ms)19702026/10/01 07:33:02 OK 1_commit_pending_closure.sql (3.12ms)19712026/10/01 07:33:02 INFO Received push request method=POST path=/api/pushes19722026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.28ms)19732026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.85ms)19742026/10/01 07:33:02 OK 2_object_stats_trigger.sql (3.01ms)19752026/10/01 07:33:02 OK 20260905000000_add_claims.sql (5.13ms)19762026/10/01 07:33:02 INFO Vacuumed table table=pending_closures19772026/10/01 07:33:02 OK 3_commit_push.sql (3.12ms)19782026/10/01 07:33:02 goose: up to current file version: 319792026/10/01 07:33:02 OK 20260905000000_add_claims.sql (5.47ms)19802026/10/01 07:33:02 OK 20241026095416_initial_model.sql (13.81ms)1981--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.49s)1982=== CONT TestPush_SignsNarinfosOfItsPendingObjects19832026/10/01 07:33:02 OK 3_commit_push.sql (2.37ms)19842026/10/01 07:33:02 goose: up to current file version: 319852026/10/01 07:33:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19862026/10/01 07:33:02 INFO Uploading v570j1rqxz68yw6hjan29mvnrbhdlk7f-ca-test (144B)19872026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (4.31ms)19882026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019892026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.99ms)19902026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (3.83ms)19912026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (4.33ms)19922026/10/01 07:33:02 INFO Vacuumed table table=pending_objects19932026/10/01 07:33:02 INFO Vacuumed table table=multipart_uploads19942026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.94ms)19952026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (3.71ms)19962026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019972026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.96ms)19982026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000019992026/10/01 07:33:02 WARN Failed to register uploaded object key=log/x7mrjj8pc1c3hwxd5wq8sqamgr5jms78-ca-test.drv error="server returned 404: 404 page not found\n"20002026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.53ms)20012026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.48ms)20022026/10/01 07:33:02 INFO Vacuumed table table=closures20032026/10/01 07:33:02 WARN Failed to register uploaded object key=v570j1rqxz68yw6hjan29mvnrbhdlk7f.ls error="server returned 404: 404 page not found\n"20042026/10/01 07:33:02 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20052026/10/01 07:33:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20062026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.5ms)20072026/10/01 07:33:02 INFO Signed narinfos id=1 count=120082026/10/01 07:33:02 INFO Uploading 1 narinfos20092026/10/01 07:33:02 OK 3_commit_push.sql (1.74ms)20102026/10/01 07:33:02 goose: up to current file version: 320112026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.85ms)20122026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.47ms)20132026/10/01 07:33:02 INFO Vacuumed table table=objects20142026/10/01 07:33:02 OK 3_commit_push.sql (1.01ms)20152026/10/01 07:33:02 goose: up to current file version: 320162026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.44ms)20172026/10/01 07:33:02 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=020182026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)20192026/10/01 07:33:02 INFO Received complete push request method=POST path=/api/pushes/1/complete20202026/10/01 07:33:02 WARN Failed to register uploaded object key=v570j1rqxz68yw6hjan29mvnrbhdlk7f.narinfo error="server returned 404: 404 page not found\n"20212026/10/01 07:33:02 OK 3_commit_push.sql (1.34ms)20222026/10/01 07:33:02 goose: up to current file version: 320232026-10-01 07:33:02.642 UTC [1450] ERROR: relation "goose_db_version" does not exist at character 3620242026-10-01 07:33:02.642 UTC [1450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20252026-10-01 07:33:02.642 UTC [1449] ERROR: relation "goose_db_version" does not exist at character 3620262026-10-01 07:33:02.642 UTC [1449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20272026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.15ms)20282026/10/01 07:33:02 INFO Vacuumed table table=pending_closures20292026/10/01 07:33:02 INFO Upload complete. (94ms)20302026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.46ms)20312026/10/01 07:33:02 INFO Vacuumed table table=pending_objects20322026/10/01 07:33:02 INFO Vacuumed table table=multipart_uploads20332026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.29ms)20342026/10/01 07:33:02 goose: successfully migrated database to version: 202609231200002035=== NAME TestClientCADerivations2036 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1248607798/001/store/v570j1rqxz68yw6hjan29mvnrbhdlk7f-ca-test2037 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2038 Compression: zstd2039 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2040 NarSize: 1442041 References: 2042 Deriver: /build/TestClientCADerivations1248607798/001/store/x7mrjj8pc1c3hwxd5wq8sqamgr5jms78-ca-test.drv2043 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2044 client_ca_test.go:185: Checking for realisation files in S3...20452026/10/01 07:33:02 INFO Vacuumed table table=closures20462026/10/01 07:33:02 OK 1_commit_pending_closure.sql (1.88ms)2047 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2048 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20492026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.35ms)20502026/10/01 07:33:02 INFO Vacuumed table table=objects20512026-10-01 07:33:02.656 UTC [1451] ERROR: relation "goose_db_version" does not exist at character 3620522026-10-01 07:33:02.656 UTC [1451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2053--- PASS: TestReadProxyHead (0.48s)2054=== CONT TestPush_RejectsBadRequests20552026/10/01 07:33:02 OK 3_commit_push.sql (8.33ms)20562026/10/01 07:33:02 goose: up to current file version: 320572026/10/01 07:33:02 OK 20241026095416_initial_model.sql (16.14ms)20582026/10/01 07:33:02 OK 20241026095416_initial_model.sql (15.21ms)20592026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)20602026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)20612026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.74ms)20622026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.45ms)20632026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)20642026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4ms)20652026/10/01 07:33:02 OK 20241026095416_initial_model.sql (12.45ms)20662026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.01ms)20672026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.18ms)2068--- PASS: TestReadProxyInvalidPath (0.49s)2069=== CONT TestService_ReadAuthMiddleware20702026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)20712026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.11ms)20722026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.67ms)20732026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.34ms)20742026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000020752026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.72ms)20762026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000020772026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.56ms)20782026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.3ms)20792026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.31ms)20802026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.62ms)20812026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.46ms)20822026/10/01 07:33:02 OK 3_commit_push.sql (1.44ms)20832026/10/01 07:33:02 goose: up to current file version: 320842026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)20852026/10/01 07:33:02 OK 3_commit_push.sql (1.33ms)20862026/10/01 07:33:02 goose: up to current file version: 320872026-10-01 07:33:02.691 UTC [1461] ERROR: relation "goose_db_version" does not exist at character 3620882026-10-01 07:33:02.691 UTC [1461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20892026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.28ms)20902026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.38ms)20912026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.5ms)20922026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000020932026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.79ms)20942026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.46ms)20952026/10/01 07:33:02 OK 3_commit_push.sql (1.21ms)20962026/10/01 07:33:02 goose: up to current file version: 320972026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.02ms)20982026-10-01 07:33:02.708 UTC [1476] ERROR: relation "goose_db_version" does not exist at character 3620992026-10-01 07:33:02.708 UTC [1476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2100--- PASS: TestReadProxy404 (0.49s)2101=== CONT TestService_RequireScope_OIDC21022026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)21032026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.79ms)21042026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)21052026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.35ms)21062026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.44ms)21072026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.21ms)21082026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000021092026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.83ms)21102026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)21112026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.34ms)21122026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.57ms)21132026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.63ms)21142026/10/01 07:33:02 OK 3_commit_push.sql (1.4ms)21152026/10/01 07:33:02 goose: up to current file version: 321162026-10-01 07:33:02.732 UTC [1492] ERROR: relation "goose_db_version" does not exist at character 3621172026-10-01 07:33:02.732 UTC [1492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21182026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)2119--- PASS: TestReadProxyNarStreaming (0.46s)2120=== CONT TestService_AuthMiddleware_OIDC21212026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.78ms)21222026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.86ms)21232026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.17ms)21242026/10/01 07:33:02 goose: successfully migrated database to version: 202609231200002125=== NAME TestClientCADerivations2126 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2127 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2128 error: binary cache 's3://bucket29?endpoint=http://localhost:34403®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1248607798/001/store'2129 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 121302026/10/01 07:33:02 OK 20241026095416_initial_model.sql (8.85ms)21312026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.62ms)21322026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.19ms)21332026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)2134--- PASS: TestClientCADerivations (0.89s)2135=== CONT TestPush_CompleteCommitsEveryRoot21362026/10/01 07:33:02 OK 3_commit_push.sql (667.53µs)21372026/10/01 07:33:02 goose: up to current file version: 321382026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3ms)21392026-10-01 07:33:02.752 UTC [1575] ERROR: relation "goose_db_version" does not exist at character 3621402026-10-01 07:33:02.752 UTC [1575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21412026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)21422026/10/01 07:33:02 OK 20260905000000_add_claims.sql (2.87ms)21432026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (1.88ms)21442026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.37ms)21452026/10/01 07:33:02 goose: successfully migrated database to version: 202609231200002146--- PASS: TestReadProxyNarinfo (0.41s)2147=== CONT TestPush_OverlappingRootsStoreOneRowPerKey21482026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.41ms)21492026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.64ms)21502026/10/01 07:33:02 OK 3_commit_push.sql (1.43ms)21512026/10/01 07:33:02 goose: up to current file version: 321522026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.36ms)21532026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)21542026/10/01 07:33:02 OK 20251218171726_add_pins.sql (10.48ms)21552026/10/01 07:33:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41517/oidc21562026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)21572026/10/01 07:33:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21582026/10/01 07:33:02 WARN Refused reserved pin name=worker-x86_64-linux21592026/10/01 07:33:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21602026/10/01 07:33:02 INFO Received create pin request method=POST path=/api/pins/my-app21612026/10/01 07:33:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2162--- PASS: TestCreatePin_ReservedPins (0.45s)2163=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21642026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.01ms)21652026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.13ms)21662026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.58ms)21672026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000021682026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.56ms)21692026/10/01 07:33:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43959/oidc21702026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.81ms)21712026/10/01 07:33:02 INFO Starting HTTP server address=127.0.0.1:3396121722026/10/01 07:33:02 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2109964018/001/proxy.sock21732026/10/01 07:33:02 OK 3_commit_push.sql (1.55ms)21742026/10/01 07:33:02 goose: up to current file version: 321752026/10/01 07:33:02 WARN mTLS auth: subject not in bound subjects subject="CN=someone"21762026/10/01 07:33:02 INFO Shutdown signal received, draining in-flight requests timeout=10s2177--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.40s)2178=== CONT TestGCSweepSkipsPendingObjects21792026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures21802026-10-01 07:33:02.824 UTC [1588] ERROR: relation "goose_db_version" does not exist at character 3621812026-10-01 07:33:02.824 UTC [1588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21822026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures21832026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures21842026/10/01 07:33:02 OK 20241026095416_initial_model.sql (17.5ms)21852026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)21862026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.01ms)21872026-10-01 07:33:02.861 UTC [1589] ERROR: relation "goose_db_version" does not exist at character 3621882026-10-01 07:33:02.861 UTC [1589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21892026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)21902026/10/01 07:33:02 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst21912026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures2192--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.41s)2193=== CONT TestTombstonedObjectOfferedWithoutWaiting21942026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.26ms)21952026-10-01 07:33:02.869 UTC [1590] ERROR: relation "goose_db_version" does not exist at character 3621962026-10-01 07:33:02.869 UTC [1590] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21972026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.94ms)2198--- PASS: TestService_Rustfstest (0.42s)2199=== CONT TestMultipartCleanup22002026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.65ms)22012026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000022022026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.44ms)22032026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.31ms)22042026/10/01 07:33:02 OK 20241026095416_initial_model.sql (9.69ms)22052026/10/01 07:33:02 OK 3_commit_push.sql (1.31ms)22062026/10/01 07:33:02 goose: up to current file version: 322072026-10-01 07:33:02.880 UTC [1592] ERROR: relation "goose_db_version" does not exist at character 3622082026-10-01 07:33:02.880 UTC [1592] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22092026-10-01 07:33:02.880 UTC [1595] ERROR: relation "goose_db_version" does not exist at character 3622102026-10-01 07:33:02.880 UTC [1595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22112026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)22122026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.9ms)22132026/10/01 07:33:02 OK 20241026095416_initial_model.sql (9.86ms)22142026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)22152026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)22162026-10-01 07:33:02.892 UTC [1597] ERROR: relation "goose_db_version" does not exist at character 3622172026-10-01 07:33:02.892 UTC [1597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22182026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4.33ms)22192026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.06ms)22202026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.93ms)22212026/10/01 07:33:02 OK 20241026095416_initial_model.sql (10.35ms)22222026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures22232026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)22242026/10/01 07:33:02 OK 20241026095416_initial_model.sql (11.52ms)22252026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (3.36ms)22262026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000022272026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)22282026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)22292026/10/01 07:33:02 OK 20260905000000_add_claims.sql (4.45ms)22302026/10/01 07:33:02 OK 1_commit_pending_closure.sql (3.38ms)22312026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.94ms)22322026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.4ms)22332026/10/01 07:33:02 OK 20251218171726_add_pins.sql (4ms)22342026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.04ms)22352026/10/01 07:33:02 OK 3_commit_push.sql (1.48ms)22362026/10/01 07:33:02 goose: up to current file version: 322372026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.48ms)22382026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000022392026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)22402026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)22412026/10/01 07:33:02 OK 1_commit_pending_closure.sql (1.92ms)22422026/10/01 07:33:02 OK 20241026095416_initial_model.sql (12.07ms)22432026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.31ms)22442026/10/01 07:33:02 OK 20260905000000_add_claims.sql (2.95ms)22452026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.15ms)22462026/10/01 07:33:02 OK 3_commit_push.sql (543.01µs)22472026/10/01 07:33:02 goose: up to current file version: 322482026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)22492026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.2ms)22502026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (3.02ms)22512026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.13ms)22522026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (1.85ms)22532026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000022542026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.13ms)22552026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000022562026/10/01 07:33:02 OK 1_commit_pending_closure.sql (1.96ms)22572026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.16ms)22582026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.9ms)22592026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)22602026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.24ms)22612026/10/01 07:33:02 OK 3_commit_push.sql (1.19ms)22622026/10/01 07:33:02 goose: up to current file version: 322632026/10/01 07:33:02 OK 3_commit_push.sql (988.93µs)22642026/10/01 07:33:02 goose: up to current file version: 322652026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures22662026/10/01 07:33:02 OK 20260905000000_add_claims.sql (8.99ms)22672026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.95ms)22682026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.41ms)22692026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000022702026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.35ms)22712026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1ms)22722026/10/01 07:33:02 OK 3_commit_push.sql (1.08ms)22732026/10/01 07:33:02 goose: up to current file version: 322742026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures22752026-10-01 07:33:02.948 UTC [1598] ERROR: relation "goose_db_version" does not exist at character 3622762026-10-01 07:33:02.948 UTC [1598] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22772026-10-01 07:33:02.949 UTC [1599] ERROR: relation "goose_db_version" does not exist at character 3622782026-10-01 07:33:02.949 UTC [1599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22792026/10/01 07:33:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22802026/10/01 07:33:02 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGU2YjZjMGEtMThhMy00ZWVkLWJkOTQtZTY0NjQ0N2RhMDIzLmRhZmE5MjZhLTk2ZGYtNDc2YS05NzgyLThlOTcwZDk3YzNmNXgxNzkwODM5OTgyOTMxMDk3MzYz22812026/10/01 07:33:02 OK 20241026095416_initial_model.sql (8.12ms)22822026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)22832026/10/01 07:33:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGU2YjZjMGEtMThhMy00ZWVkLWJkOTQtZTY0NjQ0N2RhMDIzLmRhZmE5MjZhLTk2ZGYtNDc2YS05NzgyLThlOTcwZDk3YzNmNXgxNzkwODM5OTgyOTMxMDk3MzYz parts=12284--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.50s)2285=== CONT TestServerTLSConfig2286=== RUN TestServerTLSConfig/no_client_CA2287=== PAUSE TestServerTLSConfig/no_client_CA2288=== RUN TestServerTLSConfig/missing_CA_file2289=== PAUSE TestServerTLSConfig/missing_CA_file2290=== RUN TestServerTLSConfig/not_a_PEM_file2291=== PAUSE TestServerTLSConfig/not_a_PEM_file2292=== CONT TestDeduplicatedObjectsRecordedAsPending22932026/10/01 07:33:02 OK 20241026095416_initial_model.sql (8.6ms)22942026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.05ms)22952026/10/01 07:33:02 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)22962026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.71ms)22972026/10/01 07:33:02 OK 20251218171726_add_pins.sql (3.63ms)22982026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.27ms)22992026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (1.98ms)23002026/10/01 07:33:02 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)23012026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (2.29ms)23022026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000023032026/10/01 07:33:02 OK 20260905000000_add_claims.sql (3.31ms)23042026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.85ms)23052026/10/01 07:33:02 OK 20260920000000_drop_claims.sql (2.7ms)23062026/10/01 07:33:02 OK 2_object_stats_trigger.sql (2.07ms)23072026/10/01 07:33:02 OK 3_commit_push.sql (922.49µs)23082026/10/01 07:33:02 goose: up to current file version: 323092026/10/01 07:33:02 OK 20260923120000_add_pushes.sql (1.71ms)23102026/10/01 07:33:02 goose: successfully migrated database to version: 2026092312000023112026/10/01 07:33:02 OK 1_commit_pending_closure.sql (2.36ms)23122026/10/01 07:33:02 OK 2_object_stats_trigger.sql (1.58ms)23132026/10/01 07:33:02 OK 3_commit_push.sql (1.4ms)23142026/10/01 07:33:02 goose: up to current file version: 323152026/10/01 07:33:02 INFO Aborted multipart uploads count=023162026/10/01 07:33:02 INFO Received uploads request method=POST path=/api/pending_closures23172026/10/01 07:33:03 WARN Force mode enabled - objects will be deleted immediately without grace period23182026/10/01 07:33:03 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=023192026/10/01 07:33:03 INFO Vacuumed table table=pending_closures23202026/10/01 07:33:03 INFO Vacuumed table table=pending_objects23212026/10/01 07:33:03 INFO Vacuumed table table=multipart_uploads23222026/10/01 07:33:03 INFO Vacuumed table table=closures23232026/10/01 07:33:03 INFO Vacuumed table table=objects2324--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)2325=== CONT TestService_AuthMiddleware_MTLSProxyHeader23262026/10/01 07:33:03 INFO Aborted multipart uploads count=023272026/10/01 07:33:03 WARN Force mode enabled - objects will be deleted immediately without grace period23282026-10-01 07:33:03.033 UTC [1605] ERROR: relation "goose_db_version" does not exist at character 3623292026-10-01 07:33:03.033 UTC [1605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23302026/10/01 07:33:03 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."23312026/10/01 07:33:03 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."2332--- PASS: TestFailedS3DeleteKeepsTombstone (0.55s)2333=== CONT TestProxyWriteTimeout/narinfo2334=== CONT TestProxyWriteTimeout/1_GiB_nar2335=== CONT TestProxyWriteTimeout/10_GiB_nar2336=== CONT TestProxyWriteTimeout/unknown_size2337--- PASS: TestProxyWriteTimeout (0.06s)2338 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2339 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2340 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2341 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2342=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23432026/10/01 07:33:03 INFO Received uploads request method=POST path=/2344=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23452026/10/01 07:33:03 INFO Received uploads request method=POST path=/2346=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23472026/10/01 07:33:03 INFO Received request for more parts method=POST path=/2348=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23492026/10/01 07:33:03 INFO Received complete multipart upload request method=POST path=/2350--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)2351 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2352 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2353 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2354 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2355=== CONT TestResolveDBConnectionString/flag_wins2356=== CONT TestResolveDBConnectionString/nothing_configured2357=== CONT TestResolveDBConnectionString/file_when_flag_empty2358=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2359=== CONT TestResolveDBConnectionString/missing_file_is_an_error2360--- PASS: TestResolveDBConnectionString (0.00s)2361 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2362 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2363 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2364 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2365 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2366=== CONT TestIsValidUploadKey/narinfo2367=== CONT TestIsValidUploadKey/realisation_plus_in_output2368=== CONT TestIsValidUploadKey/unknown_type2369=== CONT TestIsValidUploadKey/empty_key2370=== CONT TestIsValidUploadKey/absolute2371=== CONT TestIsValidUploadKey/traversal_nar2372=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2373=== CONT TestIsValidUploadKey/index.html2374=== CONT TestIsValidUploadKey/nix-cache-info2375=== CONT TestIsValidUploadKey/build_log_home-manager_file2376=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2377=== CONT TestIsValidUploadKey/realisation2378=== CONT TestIsValidUploadKey/traversal2379=== CONT TestIsValidUploadKey/build_log_equals2380=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2381=== CONT TestIsValidUploadKey/build_log_question_mark2382=== CONT TestIsValidUploadKey/build_log_plus_in_name2383=== CONT TestIsValidUploadKey/nar_plain2384=== CONT TestIsValidUploadKey/listing2385=== CONT TestIsValidUploadKey/build_log2386=== CONT TestIsValidUploadKey/nar_xz2387=== CONT TestIsValidUploadKey/nar_zst2388--- PASS: TestIsValidUploadKey (0.07s)2389 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2390 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2391 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2392 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2393 --- PASS: TestIsValidUploadKey/absolute (0.00s)2394 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2395 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2396 --- PASS: TestIsValidUploadKey/index.html (0.00s)2397 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2398 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2399 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2400 --- PASS: TestIsValidUploadKey/realisation (0.00s)2401 --- PASS: TestIsValidUploadKey/traversal (0.00s)2402 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2403 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2404 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2405 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2406 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2407 --- PASS: TestIsValidUploadKey/listing (0.00s)2408 --- PASS: TestIsValidUploadKey/build_log (0.00s)2409 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2410 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2411=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure24122026/10/01 07:33:03 INFO Received uploads request method=POST path=/24132026/10/01 07:33:03 OK 20241026095416_initial_model.sql (9.96ms)24142026/10/01 07:33:03 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)24152026/10/01 07:33:03 OK 20251218171726_add_pins.sql (3.61ms)24162026/10/01 07:33:03 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)2417--- PASS: TestObjectStatsTrigger (0.51s)2418=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24192026/10/01 07:33:03 INFO Received request for more parts method=POST path=/24202026/10/01 07:33:03 OK 20260905000000_add_claims.sql (3.47ms)24212026/10/01 07:33:03 OK 20260920000000_drop_claims.sql (3.13ms)24222026/10/01 07:33:03 OK 20260923120000_add_pushes.sql (2.63ms)24232026/10/01 07:33:03 goose: successfully migrated database to version: 2026092312000024242026/10/01 07:33:03 OK 1_commit_pending_closure.sql (3.03ms)24252026/10/01 07:33:03 OK 2_object_stats_trigger.sql (1.55ms)24262026/10/01 07:33:03 OK 3_commit_push.sql (1.68ms)24272026/10/01 07:33:03 goose: up to current file version: 324282026-10-01 07:33:03.093 UTC [1607] ERROR: relation "goose_db_version" does not exist at character 3624292026-10-01 07:33:03.093 UTC [1607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24302026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes24312026/10/01 07:33:03 OK 20241026095416_initial_model.sql (7.3ms)24322026/10/01 07:33:03 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)24332026/10/01 07:33:03 OK 20251218171726_add_pins.sql (2.95ms)24342026/10/01 07:33:03 INFO Received complete push request method=POST path=/api/pushes/1/complete24352026/10/01 07:33:03 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)24362026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes24372026/10/01 07:33:03 OK 20260905000000_add_claims.sql (2.6ms)24382026/10/01 07:33:03 OK 20260920000000_drop_claims.sql (2.39ms)24392026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes24402026/10/01 07:33:03 OK 20260923120000_add_pushes.sql (1.67ms)24412026/10/01 07:33:03 goose: successfully migrated database to version: 2026092312000024422026/10/01 07:33:03 OK 1_commit_pending_closure.sql (1.78ms)24432026/10/01 07:33:03 OK 2_object_stats_trigger.sql (747.19µs)24442026/10/01 07:33:03 OK 3_commit_push.sql (595.47µs)24452026/10/01 07:33:03 goose: up to current file version: 32446=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart24472026/10/01 07:33:03 INFO Received complete multipart upload request method=POST path=/24482026/10/01 07:33:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24492026/10/01 07:33:03 INFO Signed narinfos id=1 count=12450--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.50s)2451=== CONT TestClientErrorHandling/InvalidStorePath2452=== RUN TestPush_RejectsBadRequests/no_objects2453=== PAUSE TestPush_RejectsBadRequests/no_objects2454=== RUN TestPush_RejectsBadRequests/bad_root2455=== PAUSE TestPush_RejectsBadRequests/bad_root2456=== RUN TestPush_RejectsBadRequests/root_not_in_objects2457=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2458=== RUN TestPush_RejectsBadRequests/no_roots2459=== PAUSE TestPush_RejectsBadRequests/no_roots2460=== CONT TestClientErrorHandling/ServerNotAvailable2461--- PASS: TestService_ReadAuthMiddleware (0.48s)2462=== CONT TestClientErrorHandling/InvalidAuthToken2463=== CONT TestCacheConfigHandler/full_config,_no_issuer2464=== CONT TestCacheConfigHandler/no_signing_keys2465=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2466=== CONT TestCacheConfigHandler/no_cache_url_configured2467=== CONT TestIsValidCachePath/wrong_extension2468=== CONT TestIsValidCachePath/narinfo2469=== CONT TestIsValidCachePath/leading_slash2470=== CONT TestIsValidCachePath/empty2471--- PASS: TestCacheConfigHandler (0.00s)2472 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2473 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2474 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2475 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2476=== CONT TestIsValidCachePath/random_path2477=== CONT TestIsValidCachePath/invalid_char_u2478=== CONT TestIsValidCachePath/invalid_char_e2479=== CONT TestIsValidCachePath/traversal_in_middle2480=== CONT TestIsValidCachePath/traversal_parent2481=== CONT TestIsValidCachePath/index.html2482=== CONT TestIsValidCachePath/nix-cache-info2483=== CONT TestIsValidCachePath/realisation2484=== CONT TestIsValidCachePath/log2485=== CONT TestIsValidCachePath/ls2486=== CONT TestIsValidCachePath/nar_uncompressed2487=== CONT TestIsValidCachePath/nar_bz22488=== CONT TestIsValidCachePath/nar_xz2489=== CONT TestIsValidCachePath/nar_zst2490=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2491=== CONT TestIsValidCachePath/short_hash2492--- PASS: TestIsValidCachePath (0.00s)2493 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2494 --- PASS: TestIsValidCachePath/narinfo (0.00s)2495 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2496 --- PASS: TestIsValidCachePath/empty (0.00s)2497 --- PASS: TestIsValidCachePath/random_path (0.00s)2498 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2499 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2500 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2501 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2502 --- PASS: TestIsValidCachePath/index.html (0.00s)2503 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2504 --- PASS: TestIsValidCachePath/realisation (0.00s)2505 --- PASS: TestIsValidCachePath/log (0.00s)2506 --- PASS: TestIsValidCachePath/ls (0.00s)2507 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2508 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2509 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2510 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2511 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2512 --- PASS: TestIsValidCachePath/short_hash (0.00s)2513=== CONT TestParseSingleRange/none2514=== CONT TestParseSingleRange/open-ended2515=== CONT TestParseSingleRange/start_far_past_EOF2516=== CONT TestParseSingleRange/start_past_EOF2517=== CONT TestParseSingleRange/single_byte2518=== CONT TestParseSingleRange/suffix_exceeds_size2519=== CONT TestParseSingleRange/suffix2520=== CONT TestParseSingleRange/end_clamped_to_size2521=== CONT TestParseSingleRange/malformed_both_empty2522=== CONT TestParseSingleRange/closed2523=== CONT TestParseSingleRange/malformed_end_before_start2524=== CONT TestParseSingleRange/multi-range_ignored2525=== CONT TestParseSingleRange/malformed_no_dash2526=== CONT TestParseSingleRange/unknown_unit2527--- PASS: TestParseSingleRange (0.00s)2528 --- PASS: TestParseSingleRange/none (0.00s)2529 --- PASS: TestParseSingleRange/open-ended (0.00s)2530 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2531 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2532 --- PASS: TestParseSingleRange/single_byte (0.00s)2533 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2534 --- PASS: TestParseSingleRange/suffix (0.00s)2535 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2536 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2537 --- PASS: TestParseSingleRange/closed (0.00s)2538 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2539 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2540 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2541 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2542=== CONT TestServerTLSConfig/no_client_CA2543=== CONT TestServerTLSConfig/missing_CA_file2544=== CONT TestServerTLSConfig/not_a_PEM_file25452026/10/01 07:33:03 INFO Aborted multipart uploads count=02546--- PASS: TestServerTLSConfig (0.00s)2547 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2548 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2549 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2550=== CONT TestPush_RejectsBadRequests/no_objects25512026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes2552=== CONT TestPush_RejectsBadRequests/root_not_in_objects25532026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes2554=== CONT TestPush_RejectsBadRequests/no_roots25552026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes2556=== CONT TestPush_RejectsBadRequests/bad_root25572026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes2558--- PASS: TestPush_RejectsBadRequests (0.48s)2559 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2560 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2561 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2562 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)25632026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes25642026/10/01 07:33:03 WARN Force mode enabled - objects will be deleted immediately without grace period25652026-10-01 07:33:03.199 UTC [1631] ERROR: relation "goose_db_version" does not exist at character 3625662026-10-01 07:33:03.199 UTC [1631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2567--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.69s)25682026/10/01 07:33:03 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=025692026/10/01 07:33:03 INFO Received complete push request method=POST path=/api/pushes/1/complete25702026/10/01 07:33:03 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/present25712026/10/01 07:33:03 INFO Vacuumed table table=pending_closures25722026/10/01 07:33:03 INFO Vacuumed table table=pending_objects25732026/10/01 07:33:03 INFO Vacuumed table table=multipart_uploads25742026/10/01 07:33:03 INFO Received push request method=POST path=/api/pushes2575--- PASS: TestPush_CompleteCommitsEveryRoot (0.47s)25762026/10/01 07:33:03 INFO Vacuumed table table=closures25772026/10/01 07:33:03 INFO Vacuumed table table=objects25782026/10/01 07:33:03 INFO Received complete push request method=POST path=/api/pushes/2/complete25792026/10/01 07:33:03 OK 20241026095416_initial_model.sql (16.99ms)2580--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.62s)25812026/10/01 07:33:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25822026/10/01 07:33:03 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)25832026/10/01 07:33:03 OK 20251218171726_add_pins.sql (3.8ms)25842026/10/01 07:33:03 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)25852026-10-01 07:33:03.236 UTC [1653] ERROR: relation "goose_db_version" does not exist at character 3625862026-10-01 07:33:03.236 UTC [1653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25872026/10/01 07:33:03 OK 20260905000000_add_claims.sql (2.74ms)2588--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.48s)25892026/10/01 07:33:03 OK 20260920000000_drop_claims.sql (1.95ms)2590=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2591=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2592=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2593=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2594=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2595=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2596=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2597=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2598=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2599=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected26002026/10/01 07:33:03 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]2601=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2602=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26032026/10/01 07:33:03 OK 20260923120000_add_pushes.sql (2.51ms)26042026/10/01 07:33:03 goose: successfully migrated database to version: 2026092312000026052026/10/01 07:33:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGU2YjZjMGEtMThhMy00ZWVkLWJkOTQtZTY0NjQ0N2RhMDIzLmNjODQwZDk4LWQ0MDYtNDE2YS1iYmFlLWQ4MTdkYzk5MzYwY3gxNzkwODM5OTgyODMzNDgyMTYy parts=1226062026/10/01 07:33:03 OK 1_commit_pending_closure.sql (2ms)26072026/10/01 07:33:03 WARN Authentication failed token_preview=eyJhbGciOi...GudVEu-low token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2608--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2609 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2610 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2611 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2612 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)26132026/10/01 07:33:03 OK 2_object_stats_trigger.sql (793.87µs)2614--- PASS: TestRedundantMultipartUpload (0.81s)26152026/10/01 07:33:03 OK 3_commit_push.sql (654.59µs)26162026/10/01 07:33:03 goose: up to current file version: 326172026/10/01 07:33:03 OK 20241026095416_initial_model.sql (11.03ms)26182026/10/01 07:33:03 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)26192026/10/01 07:33:03 OK 20251218171726_add_pins.sql (2.99ms)26202026/10/01 07:33:03 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)26212026/10/01 07:33:03 OK 20260905000000_add_claims.sql (2.75ms)26222026/10/01 07:33:03 OK 20260920000000_drop_claims.sql (1.71ms)26232026/10/01 07:33:03 OK 20260923120000_add_pushes.sql (1.38ms)26242026/10/01 07:33:03 goose: successfully migrated database to version: 2026092312000026252026/10/01 07:33:03 OK 1_commit_pending_closure.sql (2.07ms)26262026/10/01 07:33:03 OK 2_object_stats_trigger.sql (830.35µs)26272026/10/01 07:33:03 OK 3_commit_push.sql (555.33µs)26282026/10/01 07:33:03 goose: up to current file version: 32629=== RUN TestService_RequireScope_OIDC/builder_may_write2630=== PAUSE TestService_RequireScope_OIDC/builder_may_write2631=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2632=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2633=== RUN TestService_RequireScope_OIDC/ops_may_admin2634=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2635=== RUN TestService_RequireScope_OIDC/ops_may_not_write2636=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2637=== RUN TestService_RequireScope_OIDC/reader_may_not_write2638=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2639=== RUN TestService_RequireScope_OIDC/static_token_may_admin2640=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2641=== RUN TestService_RequireScope_OIDC/static_token_may_write2642=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2643=== RUN TestService_RequireScope_OIDC/reader_may_read2644=== PAUSE TestService_RequireScope_OIDC/reader_may_read2645=== RUN TestService_RequireScope_OIDC/writer_implies_read2646=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2647=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2648=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2649=== CONT TestService_RequireScope_OIDC/builder_may_write2650=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2651=== CONT TestService_RequireScope_OIDC/static_token_may_admin2652=== CONT TestService_RequireScope_OIDC/ops_may_not_write2653=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2654=== CONT TestService_RequireScope_OIDC/ops_may_admin2655=== CONT TestService_RequireScope_OIDC/reader_may_not_write2656=== CONT TestService_RequireScope_OIDC/reader_may_read2657=== CONT TestService_RequireScope_OIDC/static_token_may_write2658=== CONT TestService_RequireScope_OIDC/writer_implies_read2659--- PASS: TestService_RequireScope_OIDC (0.57s)2660 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2661 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2662 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2663 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2664 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2665 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2666 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2667 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2668 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2669 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)26702026/10/01 07:33:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete26712026/10/01 07:33:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26722026/10/01 07:33:03 WARN mTLS auth: bound subjects configured but subject DN unavailable26732026/10/01 07:33:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2674--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.50s)26752026/10/01 07:33:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGU2YjZjMGEtMThhMy00ZWVkLWJkOTQtZTY0NjQ0N2RhMDIzLjNjZTEwYjM3LTcwMTAtNGU5ZS1hZWE5LTJmMWJiZmVjZDQ5ZngxNzkwODM5OTgyOTA1Mzg4Nzgx parts=1226762026/10/01 07:33:03 INFO Received uploads request method=POST path=/api/pending_closures2677--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.84s)26782026/10/01 07:33:03 INFO Received uploads request method=POST path=/api/pending_closures26792026/10/01 07:33:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.42259ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26802026/10/01 07:33:03 INFO Aborted multipart uploads count=026812026/10/01 07:33:03 WARN Force mode enabled - objects will be deleted immediately without grace period26822026/10/01 07:33:03 INFO Received uploads request method=POST path=/api/pending_closures26832026/10/01 07:33:03 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=026842026/10/01 07:33:03 INFO Vacuumed table table=pending_closures2685--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)26862026/10/01 07:33:03 INFO Vacuumed table table=pending_objects26872026/10/01 07:33:03 INFO Vacuumed table table=multipart_uploads26882026/10/01 07:33:03 INFO Vacuumed table table=closures26892026/10/01 07:33:03 INFO Vacuumed table table=objects2690--- PASS: TestGCSweepSkipsPendingObjects (0.54s)26912026/10/01 07:33:03 INFO Received uploads request method=POST path=/api/pending_closures26922026/10/01 07:33:03 INFO Received uploads request method=POST path=/api/pending_closures2693--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.42s)2694=== NAME TestOrphanedObjectsGC2695 orphaned_objects_gc_test.go:290: GC Test Summary:2696 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2697 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2698 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2699 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2700 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2701--- PASS: TestOrphanedObjectsGC (0.82s)2702--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.42s)27032026/10/01 07:33:03 INFO Received cleanup request method=DELETE path=/api/pending_closures27042026/10/01 07:33:03 INFO Aborted multipart uploads count=12705--- PASS: TestMultipartCleanup (0.60s)27062026/10/01 07:33:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.880429ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27072026/10/01 07:33:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27082026/10/01 07:33:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2709--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2710 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2711 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2712 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.82s)27132026/10/01 07:33:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=865.880481ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2714=== NAME TestOrphanedObjectsGCStressTest2715 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2716 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion27172026/10/01 07:33:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02718=== NAME TestPinProtectsFromGC2719 client_integration_test.go:794: Pin successfully protected closure from garbage collection2720--- PASS: TestPinProtectsFromGC (2.97s)27212026/10/01 07:33:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02722=== NAME TestClientIntegration2723 client_integration_test.go:323: Objects in database after GC:2724 client_integration_test.go:323: Successfully deleted all objects with GC --force2725--- PASS: TestClientIntegration (2.77s)2726=== NAME TestOrphanedObjectsGCStressTest2727 orphaned_objects_gc_test.go:509: Stress test completed successfully:2728 orphaned_objects_gc_test.go:510: - Active objects preserved: 202729 orphaned_objects_gc_test.go:511: - Objects deleted: 2102730 orphaned_objects_gc_test.go:512: - Total GC'd: 2102731--- PASS: TestOrphanedObjectsGCStressTest (2.23s)27322026/10/01 07:33:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.562072056s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27332026/10/01 07:33:06 WARN Rate limiter enabled after throttle name=s3-test rate=527342026/10/01 07:33:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2735=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2736 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102737 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002738--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.61s)27392026/10/01 07:33:06 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-config27402026/10/01 07:33:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.479756ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27412026/10/01 07:33:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.779125ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27422026/10/01 07:33:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=857.630465ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27432026/10/01 07:33:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.557958299s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27442026/10/01 07:33:09 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"27452026/10/01 07:33:09 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-config27462026/10/01 07:33:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.753449ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27472026/10/01 07:33:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.257454ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27482026/10/01 07:33:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=751.942813ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27492026/10/01 07:33:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.707053916s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27502026/10/01 07:33:12 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_closures27512026/10/01 07:33:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.871317ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27522026/10/01 07:33:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.484386ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27532026/10/01 07:33:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=745.600244ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27542026/10/01 07:33:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.652740681s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2755--- PASS: TestClientErrorHandling (0.00s)2756 --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)2757 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.43s)2758 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.72s)2759PASS27602026-10-01 07:33:16.071 UTC [130] LOG: received smart shutdown request27612026-10-01 07:33:16.075 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 127622026-10-01 07:33:16.088 UTC [135] LOG: shutting down27632026-10-01 07:33:16.089 UTC [135] LOG: checkpoint starting: shutdown immediate27642026-10-01 07:33:16.972 UTC [135] LOG: checkpoint complete: wrote 10373 buffers (63.3%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 20 recycled; write=0.186 s, sync=0.672 s, total=0.884 s; sync files=23917, longest=0.006 s, average=0.001 s; distance=325404 kB, estimate=325404 kB; lsn=0/1552CF58, redo lsn=0/1552CF5827652026-10-01 07:33:17.051 UTC [130] LOG: database system is shut down2766Running OIDC tests...2767=== RUN TestAudienceForIssuer2768=== PAUSE TestAudienceForIssuer2769=== RUN TestGlobMatch2770=== PAUSE TestGlobMatch2771=== RUN TestValidateToken_ValidToken2772=== PAUSE TestValidateToken_ValidToken2773=== RUN TestValidateToken_WrongAudience2774=== PAUSE TestValidateToken_WrongAudience2775=== RUN TestValidateToken_Expired2776=== PAUSE TestValidateToken_Expired2777=== RUN TestValidateToken_BoundClaimsMismatch2778=== PAUSE TestValidateToken_BoundClaimsMismatch2779=== RUN TestValidateToken_BoundSubjectMismatch2780=== PAUSE TestValidateToken_BoundSubjectMismatch2781=== RUN TestValidateToken_MultipleProviders2782=== PAUSE TestValidateToken_MultipleProviders2783=== RUN TestValidateToken_NoMatchingProvider2784=== PAUSE TestValidateToken_NoMatchingProvider2785=== RUN TestValidateToken_KubernetesServiceAccount2786=== PAUSE TestValidateToken_KubernetesServiceAccount2787=== RUN TestNewValidator_KubernetesRequiresCA2788=== PAUSE TestNewValidator_KubernetesRequiresCA2789=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2790=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2791=== RUN TestPins_ReservedForMatchingRule2792=== PAUSE TestPins_ReservedForMatchingRule2793=== RUN TestPins_TopLevelShorthand2794=== PAUSE TestPins_TopLevelShorthand2795=== RUN TestPins_ConfigValidation2796=== PAUSE TestPins_ConfigValidation2797=== RUN TestScopes_LegacyProviderDefaultsToWrite2798=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2799=== RUN TestScopes_Rules2800=== PAUSE TestScopes_Rules2801=== RUN TestScopes_ConfigValidation2802=== PAUSE TestScopes_ConfigValidation2803=== CONT TestAudienceForIssuer2804=== CONT TestValidateToken_BoundClaimsMismatch2805=== CONT TestValidateToken_KubernetesServiceAccount2806=== CONT TestValidateToken_WrongAudience2807--- PASS: TestAudienceForIssuer (0.00s)2808=== CONT TestValidateToken_ValidToken2809=== CONT TestGlobMatch2810=== RUN TestGlobMatch/foo_foo2811=== CONT TestValidateToken_Expired2812=== CONT TestValidateToken_MultipleProviders2813=== CONT TestValidateToken_NoMatchingProvider2814=== CONT TestPins_ConfigValidation2815=== CONT TestScopes_ConfigValidation2816=== CONT TestScopes_Rules2817=== CONT TestScopes_LegacyProviderDefaultsToWrite2818=== PAUSE TestGlobMatch/foo_foo2819=== RUN TestGlobMatch/foo_bar2820=== PAUSE TestGlobMatch/foo_bar2821=== RUN TestGlobMatch/*_2822=== PAUSE TestGlobMatch/*_2823=== RUN TestGlobMatch/*_anything2824=== PAUSE TestGlobMatch/*_anything2825=== RUN TestGlobMatch/foo*_foo2826=== PAUSE TestGlobMatch/foo*_foo2827=== RUN TestGlobMatch/foo*_foobar2828=== PAUSE TestGlobMatch/foo*_foobar2829=== RUN TestGlobMatch/foo*_bar2830=== PAUSE TestGlobMatch/foo*_bar2831=== RUN TestGlobMatch/*bar_bar2832=== CONT TestPins_TopLevelShorthand2833=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2834=== CONT TestValidateToken_BoundSubjectMismatch2835=== CONT TestNewValidator_KubernetesRequiresCA2836=== PAUSE TestGlobMatch/*bar_bar2837=== RUN TestGlobMatch/*bar_foobar2838=== PAUSE TestGlobMatch/*bar_foobar2839=== RUN TestGlobMatch/*bar_foo2840=== PAUSE TestGlobMatch/*bar_foo2841=== RUN TestGlobMatch/foo*bar_foobar2842=== PAUSE TestGlobMatch/foo*bar_foobar2843=== RUN TestGlobMatch/foo*bar_foo123bar2844=== PAUSE TestGlobMatch/foo*bar_foo123bar2845=== RUN TestGlobMatch/foo*bar_foobarbaz2846=== PAUSE TestGlobMatch/foo*bar_foobarbaz2847=== RUN TestGlobMatch/*/*_foo/bar2848=== PAUSE TestGlobMatch/*/*_foo/bar2849=== RUN TestGlobMatch/*/*_foo2850=== PAUSE TestGlobMatch/*/*_foo2851=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2852=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2853=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02854=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02855=== RUN TestGlobMatch/refs/*/main_refs/heads/main2856=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2857=== RUN TestGlobMatch/fo?_foo2858=== PAUSE TestGlobMatch/fo?_foo2859=== RUN TestGlobMatch/fo?_fo2860=== PAUSE TestGlobMatch/fo?_fo2861=== RUN TestGlobMatch/fo?_fooo2862=== PAUSE TestGlobMatch/fo?_fooo2863=== RUN TestGlobMatch/?oo_foo2864=== PAUSE TestGlobMatch/?oo_foo2865=== RUN TestGlobMatch/?oo_boo2866=== PAUSE TestGlobMatch/?oo_boo2867=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2868=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2869=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2870=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2871=== CONT TestGlobMatch/foo_foo2872=== CONT TestGlobMatch/?oo_boo2873=== CONT TestGlobMatch/?oo_foo2874=== CONT TestGlobMatch/fo?_fooo2875=== CONT TestGlobMatch/fo?_fo2876=== CONT TestGlobMatch/fo?_foo2877=== CONT TestGlobMatch/refs/*/main_refs/heads/main2878=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02879=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2880=== CONT TestGlobMatch/*/*_foo2881=== CONT TestGlobMatch/*/*_foo/bar2882=== CONT TestGlobMatch/foo*bar_foobarbaz2883=== CONT TestGlobMatch/foo*bar_foo123bar2884=== CONT TestGlobMatch/foo*bar_foobar2885=== CONT TestGlobMatch/*bar_foo2886=== CONT TestGlobMatch/*bar_foobar2887=== CONT TestGlobMatch/foo*_foo2888=== CONT TestGlobMatch/foo*_foobar2889=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2890=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2891=== CONT TestGlobMatch/*_anything2892=== CONT TestGlobMatch/*_2893=== CONT TestGlobMatch/foo_bar2894--- PASS: TestPins_ConfigValidation (0.00s)2895=== CONT TestGlobMatch/*bar_bar2896=== CONT TestPins_ReservedForMatchingRule2897=== CONT TestGlobMatch/foo*_bar2898--- PASS: TestGlobMatch (0.00s)2899 --- PASS: TestGlobMatch/foo_foo (0.00s)2900 --- PASS: TestGlobMatch/?oo_boo (0.00s)2901 --- PASS: TestGlobMatch/?oo_foo (0.00s)2902 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2903 --- PASS: TestGlobMatch/fo?_fo (0.00s)2904 --- PASS: TestGlobMatch/fo?_foo (0.00s)2905 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2906 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2907 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2908 --- PASS: TestGlobMatch/*/*_foo (0.00s)2909 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2910 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2911 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2912 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2913 --- PASS: TestGlobMatch/*bar_foo (0.00s)2914 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2915 --- PASS: TestGlobMatch/foo*_foo (0.00s)2916 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2917 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2918 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2919 --- PASS: TestGlobMatch/*_anything (0.00s)2920 --- PASS: TestGlobMatch/*_ (0.00s)2921 --- PASS: TestGlobMatch/foo_bar (0.00s)2922 --- PASS: TestGlobMatch/*bar_bar (0.00s)2923 --- PASS: TestGlobMatch/foo*_bar (0.00s)2924--- PASS: TestScopes_ConfigValidation (0.00s)29252026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34071/oidc29262026/10/01 07:33:18 http: TLS handshake error from 127.0.0.1:40234: remote error: tls: bad certificate2927--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)2928--- PASS: TestValidateToken_WrongAudience (0.07s)29292026/10/01 07:33:18 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12329302026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41411/oidc29312026/10/01 07:33:18 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:386632932--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)2933--- PASS: TestPins_ReservedForMatchingRule (0.12s)2934--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)29352026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33701/oidc29362026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40031/oidc2937--- PASS: TestPins_TopLevelShorthand (0.13s)2938--- PASS: TestValidateToken_ValidToken (0.13s)29392026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38585/oidc2940--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.15s)29412026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42969/oidc2942--- PASS: TestValidateToken_BoundClaimsMismatch (0.17s)29432026/10/01 07:33:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43929/oidc29442026/10/01 07:33:18 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43675/oidc29452026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35505/oidc2946--- PASS: TestValidateToken_MultipleProviders (0.19s)2947--- PASS: TestValidateToken_Expired (0.19s)29482026/10/01 07:33:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38427/oidc2949--- PASS: TestValidateToken_NoMatchingProvider (0.25s)29502026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45011/oidc29512026/10/01 07:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39739/oidc2952--- PASS: TestValidateToken_BoundSubjectMismatch (0.26s)2953--- PASS: TestScopes_Rules (0.27s)2954PASS2955Running hook tests...2956=== RUN TestSendPathsEmpty2957=== PAUSE TestSendPathsEmpty2958=== RUN TestQueueEnqueueAndFetch2959=== PAUSE TestQueueEnqueueAndFetch2960=== RUN TestQueueDeduplication2961=== PAUSE TestQueueDeduplication2962=== RUN TestQueueRemove2963=== PAUSE TestQueueRemove2964=== RUN TestQueueFetchBatchLimit2965=== PAUSE TestQueueFetchBatchLimit2966=== RUN TestQueueRetryMovesToBack2967=== PAUSE TestQueueRetryMovesToBack2968=== RUN TestQueueFetchRemoveLifecycle2969=== PAUSE TestQueueFetchRemoveLifecycle2970=== RUN TestQueueConcurrentWriters2971=== PAUSE TestQueueConcurrentWriters2972=== RUN TestQueueRemoveLargeClosure2973=== PAUSE TestQueueRemoveLargeClosure2974=== RUN TestServerClientIntegration2975=== PAUSE TestServerClientIntegration2976=== RUN TestServerQueueError2977=== PAUSE TestServerQueueError2978=== RUN TestGetListenerSocketActivation2979 server_test.go:210: === RUN TestGetListenerSocketActivation2980 --- PASS: TestGetListenerSocketActivation (0.00s)2981 PASS2982 2983--- PASS: TestGetListenerSocketActivation (0.01s)2984=== RUN TestDrainIsolatesPoisonPath2985=== PAUSE TestDrainIsolatesPoisonPath2986=== RUN TestRunNotBlockedByPoisonHead2987=== PAUSE TestRunNotBlockedByPoisonHead2988=== RUN TestDrainGivesUpWhenServerDown2989=== PAUSE TestDrainGivesUpWhenServerDown2990=== RUN TestFailedPathPrunedByLaterClosure2991=== PAUSE TestFailedPathPrunedByLaterClosure2992=== RUN TestWorkerUploadsAndRemoves2993=== PAUSE TestWorkerUploadsAndRemoves2994=== RUN TestWorkerSkipsGCdPaths2995=== PAUSE TestWorkerSkipsGCdPaths2996=== RUN TestWorkerPrunesClosureDeps2997=== PAUSE TestWorkerPrunesClosureDeps2998=== RUN TestDrainTimeout2999=== PAUSE TestDrainTimeout3000=== CONT TestSendPathsEmpty3001--- PASS: TestSendPathsEmpty (0.00s)3002=== CONT TestServerClientIntegration3003=== CONT TestServerQueueError3004=== CONT TestQueueRetryMovesToBack3005=== CONT TestWorkerUploadsAndRemoves3006=== CONT TestDrainTimeout3007=== CONT TestWorkerPrunesClosureDeps3008=== CONT TestWorkerSkipsGCdPaths3009=== CONT TestQueueRemove3010=== CONT TestQueueFetchBatchLimit3011=== CONT TestDrainGivesUpWhenServerDown30122026/10/01 07:33:18 ERROR Failed to queue paths error="permission denied" count=13013=== CONT TestFailedPathPrunedByLaterClosure3014=== CONT TestQueueConcurrentWriters3015=== CONT TestQueueRemoveLargeClosure3016=== CONT TestRunNotBlockedByPoisonHead3017=== CONT TestQueueFetchRemoveLifecycle3018=== CONT TestQueueDeduplication3019=== CONT TestQueueEnqueueAndFetch3020=== CONT TestDrainIsolatesPoisonPath3021--- PASS: TestServerClientIntegration (0.00s)3022--- PASS: TestServerQueueError (0.00s)30232026/10/01 07:33:18 INFO Upload queue status pending=230242026/10/01 07:33:18 INFO Uploading batch count=130252026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=130262026/10/01 07:33:18 INFO Uploading batch count=130272026/10/01 07:33:18 INFO Uploading batch count=230282026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=230292026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3968807825/002/a30302026/10/01 07:33:18 INFO Uploading batch count=230312026/10/01 07:33:18 INFO Uploading batch count=430322026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=430332026/10/01 07:33:18 INFO Upload queue status pending=330342026/10/01 07:33:18 INFO Upload queue status pending=230352026/10/01 07:33:18 INFO Uploading batch count=130362026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath556121573/002/bbb30372026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=13038--- PASS: TestQueueFetchBatchLimit (0.01s)30392026/10/01 07:33:18 INFO Upload queue status pending=230402026/10/01 07:33:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2466178622/002/nonexistent30412026/10/01 07:33:18 INFO Uploading batch count=230422026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3968807825/002/b3043--- PASS: TestQueueEnqueueAndFetch (0.01s)3044--- PASS: TestQueueFetchRemoveLifecycle (0.01s)30452026/10/01 07:33:18 INFO Uploading batch count=130462026/10/01 07:33:18 INFO Uploading batch count=230472026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=230482026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3968807825/002/c3049--- PASS: TestQueueRetryMovesToBack (0.02s)30502026/10/01 07:33:18 INFO Uploading batch count=13051--- PASS: TestQueueDeduplication (0.01s)3052--- PASS: TestQueueRemove (0.02s)30532026/10/01 07:33:18 INFO Uploading batch count=130542026/10/01 07:33:18 INFO Uploading batch count=130552026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3968807825/002/d30562026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=130572026/10/01 07:33:18 INFO Uploading batch count=130582026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=130592026/10/01 07:33:18 INFO Uploading batch count=230602026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=230612026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3968807825/002/e30622026/10/01 07:33:18 INFO Uploading batch count=130632026/10/01 07:33:18 ERROR Upload failed error="upload failed" count=130642026/10/01 07:33:18 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3968807825/002/f30652026/10/01 07:33:18 ERROR Drain finished with paths left in queue remaining=130662026/10/01 07:33:18 ERROR Drain finished with paths left in queue remaining=103067--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)3068--- PASS: TestDrainIsolatesPoisonPath (0.02s)3069--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3070--- PASS: TestWorkerPrunesClosureDeps (0.04s)3071--- PASS: TestWorkerSkipsGCdPaths (0.04s)3072--- PASS: TestWorkerUploadsAndRemoves (0.04s)3073--- PASS: TestQueueRemoveLargeClosure (0.15s)3074--- PASS: TestQueueConcurrentWriters (0.16s)30752026/10/01 07:33:18 ERROR Upload failed error="context deadline exceeded" count=230762026/10/01 07:33:18 ERROR Drain finished with paths left in queue remaining=43077--- PASS: TestDrainTimeout (0.21s)30782026/10/01 07:33:19 INFO Uploading batch count=130792026/10/01 07:33:19 INFO Uploading batch count=130802026/10/01 07:33:19 INFO Uploading batch count=130812026/10/01 07:33:19 ERROR Upload failed error="upload failed" count=130822026/10/01 07:33:19 INFO Uploading batch count=130832026/10/01 07:33:19 ERROR Upload failed error="upload failed" count=130842026/10/01 07:33:19 INFO Uploading batch count=130852026/10/01 07:33:19 ERROR Upload failed error="upload failed" count=130862026/10/01 07:33:19 INFO Uploading batch count=130872026/10/01 07:33:19 ERROR Upload failed error="upload failed" count=130882026/10/01 07:33:19 ERROR Drain finished with paths left in queue remaining=13089--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3090PASS