niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #286
· 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 TestSetClientTLS97=== CONT TestScriptTokenScriptFails98=== CONT TestScriptTokenEmptyCommand99--- PASS: TestScriptTokenEmptyCommand (0.00s)100=== CONT TestStreamPushRequestLine101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestEncodeNixBase32WithRealHash103=== CONT TestResolveStorePath104=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess105=== CONT TestRateLimiterFeedback106=== CONT TestPathInfoCACompatibility107=== CONT TestParsePathInfoJSONMultiplePaths108=== CONT TestParsePathInfoJSON109=== CONT TestPathInfoHashCompatibility110=== RUN TestRateLimiterFeedback/429_enables_limiter111=== CONT TestConvertHashToNix32112=== RUN TestConvertHashToNix32/SRI_format_to_Nix32113=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32114=== RUN TestConvertHashToNix32/already_Nix32_format115=== CONT TestUploadMultipart_SupersededByPeer116=== RUN TestUploadMultipart_SupersededByPeer/exists117=== CONT TestEncodeNixBase321182026/10/01 07:33:40 WARN Rate limiter enabled after throttle name=server-test rate=5119=== RUN TestEncodeNixBase32/test_string_hash120=== PAUSE TestEncodeNixBase32/test_string_hash121=== CONT TestDumpPathWriterError122=== CONT TestStreamPushBatchesUnderLoad123=== CONT TestDumpPathSingleFile124=== CONT TestDumpPathMatchesNix1252026/10/01 07:33:40 ERROR Upload failed error=boom count=1126=== CONT TestStreamPushIsolatesFailures127=== CONT TestClientSignaturesByStorePath128=== CONT TestStreamPushReportsSignatures129=== CONT TestSetClientTLSDoesNotMutateDefaultTransport130--- PASS: TestEncodeNixBase32WithRealHash (0.00s)131=== CONT TestStreamPushGivesUpOnDeadServer132=== CONT TestGetStorePathHash133=== PAUSE TestRateLimiterFeedback/429_enables_limiter134=== RUN TestRateLimiterFeedback/503_enables_limiter1352026/10/01 07:33:40 ERROR Upload failed error="bad path" count=3136=== PAUSE TestRateLimiterFeedback/503_enables_limiter137=== RUN TestPathInfoCACompatibility/null_ca_field138=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths139=== RUN TestParsePathInfoJSON/Nix_format1402026/10/01 07:33:40 ERROR Upload failed error="connection refused" count=201412026/10/01 07:33:40 ERROR Server seems unavailable, giving up on batch untried=171422026/10/01 07:33:40 ERROR Upload failed error=boom count=1143=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)144=== PAUSE TestConvertHashToNix32/already_Nix32_format145=== PAUSE TestUploadMultipart_SupersededByPeer/exists146=== RUN TestEncodeNixBase32/empty_input147=== CONT TestShellSplitErrors148=== RUN TestGetStorePathHash/valid_store_path149--- PASS: TestResolveStorePath (0.00s)150=== CONT TestFileTokenEmpty151=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== PAUSE TestParsePathInfoJSON/Nix_format153=== RUN TestParsePathInfoJSON/Lix_format154--- PASS: TestShellSplitErrors (0.00s)155--- PASS: TestClientSignaturesByStorePath (0.00s)156--- PASS: TestScriptTokenScriptFails (0.00s)157=== CONT TestScriptTokenBadJSON158=== CONT TestScriptTokenEmptyToken159=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter160=== PAUSE TestPathInfoCACompatibility/null_ca_field161=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths162=== RUN TestUploadMultipart_SupersededByPeer/missing163=== CONT TestScriptTokenCachesUntilRefresh164=== PAUSE TestGetStorePathHash/valid_store_path165=== PAUSE TestEncodeNixBase32/empty_input166=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon167=== RUN TestConvertHashToNix32/invalid_format168--- PASS: TestStreamPushReportsSignatures (0.00s)169--- PASS: TestStreamPushIsolatesFailures (0.00s)170=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter171=== PAUSE TestParsePathInfoJSON/Lix_format172=== PAUSE TestConvertHashToNix32/invalid_format173=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon174=== RUN TestPathInfoCACompatibility/old_string_format_-_text175--- PASS: TestDoServerRequestAttachesToken (0.01s)176=== CONT TestScriptTokenNoExpiryRerunsEveryCall177=== CONT TestFilterOversizedClosures178=== RUN TestGetStorePathHash/basename_without_hyphen_should_error179=== PAUSE TestUploadMultipart_SupersededByPeer/missing180=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error181=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter182=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== RUN TestParsePathInfoJSON/empty_input184--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)185--- PASS: TestFileTokenEmpty (0.00s)186=== CONT TestPartSizeForNAR187--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)188=== CONT TestStaticToken189--- PASS: TestStaticToken (0.00s)190=== CONT TestCaseHackSuffix191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text192=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1932026/10/01 07:33:40 WARN Rate limiter enabled after throttle name=server-test rate=5194=== RUN TestFilterOversizedClosures/no_limit_keeps_everything195=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1962026/10/01 07:33:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35107197=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive198=== CONT TestFileTokenReadsAndCaches199=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive200=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI202=== CONT TestStreamPushReportsEveryPath203=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512204=== PAUSE TestParsePathInfoJSON/empty_input205=== CONT TestShellSplit2062026/10/01 07:33:40 WARN Rate limiter backed off name=server-test rate=52072026/10/01 07:33:40 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35107208=== CONT TestUploadMultipart_PartsInParallel209=== CONT TestSetClientTLSErrors210=== CONT TestConvertHashToNix32/already_Nix32_format211=== CONT TestUploadMultipart_SupersededByPeer/exists212=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything213=== CONT TestFileTokenMissing214--- PASS: TestScriptTokenBadJSON (0.00s)215=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error216=== RUN TestPartSizeForNAR/zero_stays_at_minimum217=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum218=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error219=== RUN TestSetClientTLS/rejects_connection_without_client_cert220=== RUN TestPathInfoCACompatibility/new_structured_format_-_text221=== CONT TestRegisterUploadedObjectReusesConnections222=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512223=== RUN TestParsePathInfoJSON/whitespace_only224=== CONT TestEncodeNixBase32/test_string_hash225=== CONT TestEncodeNixBase32/empty_input226=== CONT TestConvertHashToNix32/invalid_format227=== CONT TestConvertHashToNix32/SRI_format_to_Nix32228=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped229--- PASS: TestScriptTokenEmptyToken (0.00s)230=== RUN TestSetClientTLSErrors/missing_cert_file231=== CONT TestUploadMultipart_SupersededByPeer/missing232=== CONT TestRateLimiterFeedback/503_enables_limiter233--- PASS: TestShellSplit (0.00s)234=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped235=== RUN TestFilterOversizedClosures/all_closures_skipped236=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths237=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths238=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)239=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512240=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI241=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon242=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert243=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA244=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA245=== RUN TestSetClientTLS/preserves_debug_logging_transport246=== PAUSE TestSetClientTLS/preserves_debug_logging_transport247=== CONT TestSetClientTLS/rejects_connection_without_client_cert2482026/10/01 07:33:40 WARN Rate limiter enabled after throttle name=server-test rate=5249=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error250=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error251=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text252=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error253=== CONT TestGetStorePathHash/valid_store_path254=== PAUSE TestParsePathInfoJSON/whitespace_only255=== CONT TestRateLimiterFeedback/429_enables_limiter256=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter257--- PASS: TestStreamPushReportsEveryPath (0.00s)2582026/10/01 07:33:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39413259=== CONT TestSetClientTLS/preserves_debug_logging_transport260=== PAUSE TestSetClientTLSErrors/missing_cert_file261=== RUN TestPartSizeForNAR/small_stays_at_minimum262=== PAUSE TestFilterOversizedClosures/all_closures_skipped263=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter264--- PASS: TestFileTokenReadsAndCaches (0.00s)265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)266--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)267--- PASS: TestFileTokenMissing (0.00s)268--- PASS: TestEncodeNixBase32 (0.00s)269 --- PASS: TestEncodeNixBase32/empty_input (0.00s)270 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)271=== RUN TestSetClientTLSErrors/missing_key_file272=== PAUSE TestSetClientTLSErrors/missing_key_file273=== RUN TestSetClientTLSErrors/missing_ca_file274=== PAUSE TestSetClientTLSErrors/missing_ca_file275=== RUN TestSetClientTLSErrors/invalid_ca_file276=== PAUSE TestSetClientTLSErrors/invalid_ca_file277=== CONT TestSetClientTLSErrors/missing_cert_file278=== PAUSE TestPartSizeForNAR/small_stays_at_minimum279=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum280=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum281=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts282=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts283=== RUN TestPartSizeForNAR/1_TiB284=== PAUSE TestPartSizeForNAR/1_TiB285=== RUN TestPartSizeForNAR/5_TiB_S3_max_object286=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object287=== RUN TestPartSizeForNAR/capped_at_5_GiB288=== PAUSE TestPartSizeForNAR/capped_at_5_GiB289=== CONT TestPartSizeForNAR/zero_stays_at_minimum290=== CONT TestFilterOversizedClosures/no_limit_keeps_everything291=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2922026/10/01 07:33:40 WARN Rate limiter backed off name=server-test rate=5293=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method294=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method295=== CONT TestSetClientTLSErrors/missing_key_file296=== CONT TestPathInfoCACompatibility/new_structured_format_-_text297=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error298=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method299=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive300=== CONT TestPathInfoCACompatibility/old_string_format_-_text301=== CONT TestPartSizeForNAR/small_stays_at_minimum302=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts303=== CONT TestSetClientTLSErrors/missing_ca_file304=== CONT TestPartSizeForNAR/1_TiB305=== RUN TestParsePathInfoJSON/invalid_JSON306=== CONT TestSetClientTLSErrors/invalid_ca_file3072026/10/01 07:33:40 WARN Rate limiter enabled after throttle name=server-test rate=53082026/10/01 07:33:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42607309=== CONT TestPartSizeForNAR/capped_at_5_GiB310=== CONT TestPartSizeForNAR/5_TiB_S3_max_object311=== CONT TestPathInfoCACompatibility/null_ca_field312=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum313=== CONT TestFilterOversizedClosures/all_closures_skipped3142026/10/01 07:33:40 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=50315=== CONT TestGetStorePathHash/basename_without_hyphen_should_error3162026/10/01 07:33:40 WARN Rate limiter backed off name=server-test rate=5317=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3182026/10/01 07:33:40 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=2000319=== PAUSE TestParsePathInfoJSON/invalid_JSON320=== CONT TestParsePathInfoJSON/Nix_format321--- PASS: TestConvertHashToNix32 (0.00s)322 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)323 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)324 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)325--- PASS: TestDumpPathSingleFile (0.05s)326--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)327--- PASS: TestCaseHackSuffix (0.05s)328=== CONT TestParsePathInfoJSON/invalid_JSON329=== CONT TestParsePathInfoJSON/whitespace_only330=== CONT TestParsePathInfoJSON/empty_input331=== CONT TestParsePathInfoJSON/Lix_format332--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)335--- PASS: TestPathInfoHashCompatibility (0.05s)336 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)337 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)338 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)339 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)340--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)341 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.05s)342 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)343--- PASS: TestPathInfoCACompatibility (0.06s)344 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)345 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)346 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)348 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)349--- PASS: TestGetStorePathHash (0.06s)350 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)351 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)352 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)353 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)354--- PASS: TestFilterOversizedClosures (0.06s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)358--- PASS: TestParsePathInfoJSON (0.07s)359 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)361 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)362 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)363 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)364--- PASS: TestRateLimiterFeedback (0.01s)365 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)366 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)369--- PASS: TestPartSizeForNAR (0.06s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)372 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)373 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)374 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)375 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)376 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)377--- PASS: TestSetClientTLSErrors (0.05s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3822026/10/01 07:33:40 http: TLS handshake error from 127.0.0.1:36212: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.06s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestStreamPushRequestLine (0.08s)388--- PASS: TestDumpPathWriterError (0.08s)389--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)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/postgres2826720489/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/postgres2826720489/data -l logfile start422423/build/postgres2826720489:5432 - no response4242026-10-01 07:33:42.608 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 07:33:42.609 UTC [128] LOG: listening on Unix socket "/build/postgres2826720489/.s.PGSQL.5432"4262026-10-01 07:33:42.613 UTC [135] LOG: database system was shut down at 2026-10-01 07:33:42 UTC4272026-10-01 07:33:42.616 UTC [128] LOG: database system is ready to accept connections428/build/postgres2826720489:5432 - accepting connections429{"timestamp":"2026-10-01T07:33:42.808431889Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"572539ef-d400-4fdc-a392-f8b09344debc","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 07:33:42.995 UTC [371] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 07:33:42.995 UTC [371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 07:33:43 OK 20241026095416_initial_model.sql (136.8ms)4742026/10/01 07:33:43 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)4752026/10/01 07:33:43 OK 20251218171726_add_pins.sql (3.16ms)4762026/10/01 07:33:43 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)4772026/10/01 07:33:43 OK 20260905000000_add_claims.sql (3.38ms)4782026/10/01 07:33:43 OK 20260920000000_drop_claims.sql (1.91ms)4792026/10/01 07:33:43 OK 20260923120000_add_pushes.sql (1.61ms)4802026/10/01 07:33:43 goose: successfully migrated database to version: 202609231200004812026/10/01 07:33:43 OK 1_commit_pending_closure.sql (1.82ms)4822026/10/01 07:33:43 OK 2_object_stats_trigger.sql (723.75µs)4832026/10/01 07:33:43 OK 3_commit_push.sql (605.89µs)4842026/10/01 07:33:43 goose: up to current file version: 34852026/10/01 07:33:43 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 07:33:43 INFO lead: released remote=192.0.2.1:12344872026/10/01 07:33:43 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 07:33:43 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.92s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 07:33:43.887 UTC [381] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 07:33:43.887 UTC [381] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 07:33:43 OK 20241026095416_initial_model.sql (10.01ms)4962026/10/01 07:33:43 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)4972026/10/01 07:33:43 OK 20251218171726_add_pins.sql (2.86ms)4982026/10/01 07:33:43 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)4992026/10/01 07:33:43 OK 20260905000000_add_claims.sql (2.98ms)5002026/10/01 07:33:43 OK 20260920000000_drop_claims.sql (2.24ms)5012026/10/01 07:33:43 OK 20260923120000_add_pushes.sql (1.47ms)5022026/10/01 07:33:43 goose: successfully migrated database to version: 202609231200005032026/10/01 07:33:43 OK 1_commit_pending_closure.sql (1.61ms)5042026/10/01 07:33:43 OK 2_object_stats_trigger.sql (805.25µs)5052026/10/01 07:33:43 OK 3_commit_push.sql (622.07µs)5062026/10/01 07:33:43 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestGCTaskStore_StartNew533=== PAUSE TestGCTaskStore_StartNew534=== RUN TestGCTaskStore_DeduplicateSameParams535=== PAUSE TestGCTaskStore_DeduplicateSameParams536=== RUN TestGCTaskStore_ConflictDifferentParams537=== PAUSE TestGCTaskStore_ConflictDifferentParams538=== RUN TestGCTaskStore_GetEmpty539=== PAUSE TestGCTaskStore_GetEmpty540=== RUN TestGCTaskStore_GetReturnsLatest541=== PAUSE TestGCTaskStore_GetReturnsLatest542=== RUN TestGCTaskStore_CompletedAllowsNewTask543=== PAUSE TestGCTaskStore_CompletedAllowsNewTask544=== RUN TestGCTaskStore_PhaseUpdates545=== PAUSE TestGCTaskStore_PhaseUpdates546=== RUN TestGCTaskStore_Fail547=== PAUSE TestGCTaskStore_Fail548=== RUN TestGracefulShutdownDrainsInflight549=== PAUSE TestGracefulShutdownDrainsInflight550=== RUN TestService_healthCheckHandler551=== PAUSE TestService_healthCheckHandler552=== RUN TestService_readinessHandler553=== PAUSE TestService_readinessHandler554=== RUN TestGenerateLandingPage555=== PAUSE TestGenerateLandingPage556=== RUN TestCacheConfigHandlerMaxNarSize557=== PAUSE TestCacheConfigHandlerMaxNarSize558=== RUN TestCreatePendingClosureRejectsOversizedNAR559=== PAUSE TestCreatePendingClosureRejectsOversizedNAR560=== RUN TestNARDeduplicationMetadataUploadBug561=== PAUSE TestNARDeduplicationMetadataUploadBug562=== RUN TestMetricsInventory563=== PAUSE TestMetricsInventory564=== RUN TestService_NativeMTLS565=== PAUSE TestService_NativeMTLS566=== RUN TestServerTLSConfig567=== PAUSE TestServerTLSConfig568=== RUN TestMultipartCleanup569=== PAUSE TestMultipartCleanup570=== RUN TestObjectStatsTrigger571=== PAUSE TestObjectStatsTrigger572=== RUN TestOrphanedObjectsGC573=== PAUSE TestOrphanedObjectsGC574=== RUN TestOrphanedObjectsGCStressTest575=== PAUSE TestOrphanedObjectsGCStressTest576=== RUN TestCreatePin_ReservedPins577=== PAUSE TestCreatePin_ReservedPins578=== RUN TestParseSingleRange579=== PAUSE TestParseSingleRange580=== RUN TestProxyHeadersOnlyTrustedOnSocket581=== PAUSE TestProxyHeadersOnlyTrustedOnSocket582=== RUN TestIsValidCachePath583=== PAUSE TestIsValidCachePath584=== RUN TestReadProxyNarinfo585=== PAUSE TestReadProxyNarinfo586=== RUN TestReadProxyNarinfoAlreadyDecompressed587=== PAUSE TestReadProxyNarinfoAlreadyDecompressed588=== RUN TestReadProxyNarStreaming589=== PAUSE TestReadProxyNarStreaming590=== RUN TestReadProxy404591=== PAUSE TestReadProxy404592=== RUN TestReadProxyInvalidPath593=== PAUSE TestReadProxyInvalidPath594=== RUN TestReadProxyHead595=== PAUSE TestReadProxyHead596=== RUN TestReadProxyConditionalGet597=== PAUSE TestReadProxyConditionalGet598=== RUN TestReadProxyRootRedirectsToIndexHTML599=== PAUSE TestReadProxyRootRedirectsToIndexHTML600=== RUN TestReadProxyDisabled601=== PAUSE TestReadProxyDisabled602=== RUN TestReadRedirectNar603=== PAUSE TestReadRedirectNar604=== RUN TestReadRedirectKeepsNarinfoProxied605=== PAUSE TestReadRedirectKeepsNarinfoProxied606=== RUN TestReadProxyRangeRequest607=== PAUSE TestReadProxyRangeRequest608=== RUN TestReadRedirectUsesPublicS3URL609=== PAUSE TestReadRedirectUsesPublicS3URL610=== RUN TestPush_OverlappingRootsStoreOneRowPerKey611=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey612=== RUN TestPush_CompleteCommitsEveryRoot613=== PAUSE TestPush_CompleteCommitsEveryRoot614=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit615=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit616=== RUN TestPush_RejectsBadRequests617=== PAUSE TestPush_RejectsBadRequests618=== RUN TestPush_SignsNarinfosOfItsPendingObjects619=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects620=== RUN TestRedundantMultipartUpload621=== PAUSE TestRedundantMultipartUpload622=== RUN TestCompleteMultipartUpload_ErrorButObjectExists623=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists624=== RUN TestCompletedNarNotReofferedAcrossClosures625=== PAUSE TestCompletedNarNotReofferedAcrossClosures626=== RUN TestPresignedUploadRegisteredBeforeCommit627=== PAUSE TestPresignedUploadRegisteredBeforeCommit628=== RUN TestService_Rustfstest629=== PAUSE TestService_Rustfstest630=== RUN TestParseSize631=== PAUSE TestParseSize632=== RUN TestSkippedUploadsHandler633=== PAUSE TestSkippedUploadsHandler634=== RUN TestSystemdListenerNotActivated635--- PASS: TestSystemdListenerNotActivated (0.00s)636=== RUN TestWatchdogBeatsWhenHealthy637--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)638=== RUN TestWatchdogSkipsWhenUnhealthy6392026/10/01 07:33:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 07:33:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"649--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)650=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle651=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle652=== RUN TestProxyWriteTimeout653=== PAUSE TestProxyWriteTimeout654=== RUN TestIsValidUploadKey655=== PAUSE TestIsValidUploadKey656=== RUN TestUploadHandlersRejectInvalidKeys657=== PAUSE TestUploadHandlersRejectInvalidKeys658=== RUN TestUploadHandlersRejectOversizedBody659=== PAUSE TestUploadHandlersRejectOversizedBody660=== RUN TestService_cleanupPendingClosuresHandler661=== PAUSE TestService_cleanupPendingClosuresHandler662=== RUN TestService_createPendingClosureHandler663=== PAUSE TestService_createPendingClosureHandler664=== RUN TestService_verifyS3Integrity665=== PAUSE TestService_verifyS3Integrity666=== RUN TestCompleteMultipartUnregistered667=== PAUSE TestCompleteMultipartUnregistered668=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT669=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT670=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== CONT TestService_Rustfstest672=== CONT TestService_cleanupPendingClosuresHandler673=== CONT TestPresignedUploadRegisteredBeforeCommit674=== CONT TestGracefulShutdownDrainsInflight675=== CONT TestCompleteMultipartUnregistered676=== CONT TestSkippedUploadsHandler677=== CONT TestParseSize6782026/10/01 07:33:44 INFO Starting HTTP server address=127.0.0.1:42653679--- PASS: TestParseSize (0.00s)680=== CONT TestClientMultipleUploads6812026/10/01 07:33:44 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000682=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT6832026/10/01 07:33:44 INFO Shutdown signal received, draining in-flight requests timeout=10s684=== CONT TestService_verifyS3Integrity685=== CONT TestUploadHandlersRejectInvalidKeys686=== CONT TestUploadHandlersRejectOversizedBody687=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info688=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info689=== CONT TestService_createPendingClosureHandler690=== CONT TestClientIntegration691=== CONT TestLeadEndsOnShutdown692=== CONT TestLeadElectsOneAndHandsOver693=== CONT TestResolveDBConnectionString694=== CONT TestClientFallsBackToClosures695=== CONT TestClientPushesUseOnePush696=== CONT TestPinProtectsFromGC697=== CONT TestClientSharedPathCommittedMidPush698=== CONT TestClientWithDependencies699=== CONT TestGCBugBareHashReferences700=== CONT TestService_AuthMiddleware701=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal702=== RUN TestResolveDBConnectionString/flag_wins703=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal704=== PAUSE TestResolveDBConnectionString/flag_wins705=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key706=== RUN TestResolveDBConnectionString/file_when_flag_empty707=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key708=== PAUSE TestResolveDBConnectionString/file_when_flag_empty709=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key710=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key711=== RUN TestResolveDBConnectionString/missing_file_is_an_error712=== CONT TestTombstonedObjectOfferedWithoutWaiting713=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error714=== RUN TestResolveDBConnectionString/PGHOST_allows_empty715=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty716=== RUN TestResolveDBConnectionString/nothing_configured717=== PAUSE TestResolveDBConnectionString/nothing_configured718=== CONT TestSweepSkipsRowsLockedByPush719--- PASS: TestSkippedUploadsHandler (0.06s)720=== CONT TestFailedS3DeleteKeepsTombstone721--- PASS: TestGracefulShutdownDrainsInflight (0.07s)722=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection7232026-10-01 07:33:44.299 UTC [447] ERROR: relation "goose_db_version" does not exist at character 367242026-10-01 07:33:44.299 UTC [447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC725=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure726=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure727=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart728=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart729=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts730=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts731=== CONT TestRegisterCompletedObjectNeedsPendingRow7322026-10-01 07:33:44.319 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367332026-10-01 07:33:44.319 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7342026-10-01 07:33:44.335 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367352026-10-01 07:33:44.335 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7362026-10-01 07:33:44.340 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367372026-10-01 07:33:44.340 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026/10/01 07:33:44 OK 20241026095416_initial_model.sql (23.7ms)7392026/10/01 07:33:44 OK 20241026095416_initial_model.sql (16.12ms)7402026-10-01 07:33:44.356 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367412026-10-01 07:33:44.356 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (4.08ms)7432026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.95ms)7442026/10/01 07:33:44 OK 20251218171726_add_pins.sql (20.15ms)7452026/10/01 07:33:44 OK 20251218171726_add_pins.sql (20.23ms)7462026/10/01 07:33:44 OK 20241026095416_initial_model.sql (31.83ms)7472026/10/01 07:33:44 OK 20241026095416_initial_model.sql (32.79ms)7482026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)7492026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)7502026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (7.4ms)7512026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.97ms)7522026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.6ms)7532026-10-01 07:33:44.390 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367542026-10-01 07:33:44.390 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026-10-01 07:33:44.390 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367562026-10-01 07:33:44.390 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026-10-01 07:33:44.390 UTC [457] ERROR: relation "goose_db_version" does not exist at character 367582026-10-01 07:33:44.390 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026-10-01 07:33:44.391 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367602026-10-01 07:33:44.391 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7612026-10-01 07:33:44.394 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367622026-10-01 07:33:44.394 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.93ms)7642026/10/01 07:33:44 OK 20251218171726_add_pins.sql (7.65ms)7652026-10-01 07:33:44.396 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367662026-10-01 07:33:44.396 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7672026-10-01 07:33:44.397 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367682026-10-01 07:33:44.397 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7692026-10-01 07:33:44.397 UTC [462] ERROR: relation "goose_db_version" does not exist at character 367702026-10-01 07:33:44.397 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026-10-01 07:33:44.397 UTC [463] ERROR: relation "goose_db_version" does not exist at character 367722026-10-01 07:33:44.397 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7732026/10/01 07:33:44 OK 20260905000000_add_claims.sql (16.68ms)7742026/10/01 07:33:44 OK 20251218171726_add_pins.sql (18.4ms)7752026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (14.35ms)7762026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200007772026/10/01 07:33:44 OK 20241026095416_initial_model.sql (28.97ms)7782026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (13.52ms)7792026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (5.43ms)7802026/10/01 07:33:44 OK 1_commit_pending_closure.sql (4.1ms)7812026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.86ms)7822026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (7.57ms)7832026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.58ms)7842026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.3ms)7852026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200007862026/10/01 07:33:44 OK 20260905000000_add_claims.sql (6.48ms)7872026/10/01 07:33:44 OK 3_commit_push.sql (1.66ms)7882026/10/01 07:33:44 goose: up to current file version: 37892026/10/01 07:33:44 OK 20260905000000_add_claims.sql (5.28ms)7902026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.91ms)7912026/10/01 07:33:44 OK 1_commit_pending_closure.sql (4ms)7922026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.95ms)7932026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.23ms)7942026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.13ms)7952026-10-01 07:33:44.424 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367962026-10-01 07:33:44.424 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-10-01 07:33:44.425 UTC [466] ERROR: relation "goose_db_version" does not exist at character 367982026-10-01 07:33:44.425 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-10-01 07:33:44.425 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368002026-10-01 07:33:44.425 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026-10-01 07:33:44.426 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368022026-10-01 07:33:44.426 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8032026-10-01 07:33:44.427 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368042026-10-01 07:33:44.427 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026-10-01 07:33:44.427 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368062026-10-01 07:33:44.427 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026-10-01 07:33:44.427 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368082026-10-01 07:33:44.427 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026-10-01 07:33:44.428 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368102026-10-01 07:33:44.428 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (9.79ms)8122026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200008132026/10/01 07:33:44 OK 3_commit_push.sql (8.77ms)8142026/10/01 07:33:44 goose: up to current file version: 38152026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (11.29ms)8162026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (7.15ms)8172026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200008182026/10/01 07:33:44 OK 20241026095416_initial_model.sql (21.23ms)8192026/10/01 07:33:44 OK 20241026095416_initial_model.sql (21.16ms)8202026/10/01 07:33:44 OK 20241026095416_initial_model.sql (18.13ms)8212026/10/01 07:33:44 OK 20241026095416_initial_model.sql (20.66ms)8222026/10/01 07:33:44 OK 20241026095416_initial_model.sql (17.63ms)8232026/10/01 07:33:44 OK 20241026095416_initial_model.sql (20.88ms)8242026/10/01 07:33:44 OK 20241026095416_initial_model.sql (17.83ms)8252026/10/01 07:33:44 OK 20241026095416_initial_model.sql (21.64ms)8262026/10/01 07:33:44 OK 20241026095416_initial_model.sql (16.85ms)8272026-10-01 07:33:44.433 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368282026-10-01 07:33:44.433 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.74ms)8302026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)8312026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)8322026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)8332026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)8342026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)8352026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)8362026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)8372026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)8382026/10/01 07:33:44 OK 1_commit_pending_closure.sql (4.01ms)8392026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2ms)8402026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.51ms)8412026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (4.01ms)8422026/10/01 07:33:44 OK 3_commit_push.sql (1.65ms)8432026/10/01 07:33:44 goose: up to current file version: 38442026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.71ms)8452026/10/01 07:33:44 OK 3_commit_push.sql (1.56ms)8462026/10/01 07:33:44 goose: up to current file version: 38472026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.27ms)8482026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.35ms)8492026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.24ms)8502026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.28ms)8512026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.34ms)8522026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.98ms)8532026/10/01 07:33:44 OK 20251218171726_add_pins.sql (6ms)8542026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.91ms)8552026/10/01 07:33:44 OK 20251218171726_add_pins.sql (7.02ms)8562026/10/01 07:33:44 OK 20251218171726_add_pins.sql (7.14ms)8572026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.8ms)8582026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200008592026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)8602026/10/01 07:33:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8612026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.86ms)8622026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)8632026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.93ms)8642026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)8652026/10/01 07:33:44 OK 20241026095416_initial_model.sql (14.81ms)8662026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)8672026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.51ms)8682026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.57ms)8692026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.01ms)8702026/10/01 07:33:44 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst8712026/10/01 07:33:44 OK 20241026095416_initial_model.sql (14.54ms)872--- PASS: TestCompleteMultipartUnregistered (0.28s)873=== CONT TestGCSweepDeliversEachKeyOnce8742026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.23ms)8752026/10/01 07:33:44 OK 20241026095416_initial_model.sql (15.74ms)8762026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (6.42ms)8772026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)8782026/10/01 07:33:44 OK 20241026095416_initial_model.sql (15.71ms)8792026/10/01 07:33:44 OK 2_object_stats_trigger.sql (3.04ms)8802026/10/01 07:33:44 OK 20241026095416_initial_model.sql (16.24ms)8812026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.9ms)8822026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.94ms)8832026/10/01 07:33:44 OK 20241026095416_initial_model.sql (16.99ms)8842026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.94ms)8852026/10/01 07:33:44 OK 20241026095416_initial_model.sql (17.48ms)8862026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)8872026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.42ms)8882026/10/01 07:33:44 OK 3_commit_push.sql (1.89ms)8892026/10/01 07:33:44 goose: up to current file version: 38902026/10/01 07:33:44 OK 20241026095416_initial_model.sql (16.42ms)8912026/10/01 07:33:44 OK 20260905000000_add_claims.sql (5ms)8922026/10/01 07:33:44 OK 20260905000000_add_claims.sql (5.37ms)8932026/10/01 07:33:44 OK 20260905000000_add_claims.sql (5.64ms)8942026/10/01 07:33:44 OK 20260905000000_add_claims.sql (5.51ms)8952026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)8962026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)8972026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.74ms)8982026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)8992026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)9002026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.14ms)9012026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.94ms)9022026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.3ms)9032026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.17ms)9042026/10/01 07:33:44 OK 20241026095416_initial_model.sql (13.22ms)9052026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.45ms)9062026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)9072026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.94ms)9082026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.11ms)9092026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.04ms)9102026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.95ms)9112026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.17ms)9122026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.93ms)9132026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.89ms)9142026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.71ms)9152026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009162026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009172026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.04ms)9182026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)9192026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.56ms)9202026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009212026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.88ms)9222026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.2ms)9232026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009242026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.13ms)9252026-10-01 07:33:44.459 UTC [474] ERROR: relation "goose_db_version" does not exist at character 369262026-10-01 07:33:44.459 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.52ms)9282026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)9292026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.52ms)9302026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009312026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009322026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.66ms)9332026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.59ms)9342026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009352026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.37ms)9362026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009372026/10/01 07:33:44 OK 20251218171726_add_pins.sql (3.87ms)9382026/10/01 07:33:44 OK 20251218171726_add_pins.sql (5.37ms)9392026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.85ms)9402026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.8ms)9412026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.59ms)9422026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200009432026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.76ms)9442026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.34ms)9452026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.1ms)9462026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.89ms)9472026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.64ms)9482026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)9492026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.8ms)9502026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.8ms)9512026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.08ms)9522026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.16ms)9532026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)9542026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.82ms)9552026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.33ms)9562026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)9572026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.04ms)9582026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.1ms)9592026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)9602026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.05ms)9612026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.88ms)9622026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.94ms)9632026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.78ms)9642026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.97ms)9652026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)9662026/10/01 07:33:44 OK 3_commit_push.sql (2.13ms)9672026/10/01 07:33:44 goose: up to current file version: 39682026/10/01 07:33:44 OK 3_commit_push.sql (1.47ms)9692026/10/01 07:33:44 goose: up to current file version: 39702026/10/01 07:33:44 OK 3_commit_push.sql (2.21ms)9712026/10/01 07:33:44 goose: up to current file version: 39722026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)9732026/10/01 07:33:44 OK 3_commit_push.sql (1.46ms)9742026/10/01 07:33:44 OK 3_commit_push.sql (1.35ms)9752026/10/01 07:33:44 goose: up to current file version: 39762026/10/01 07:33:44 OK 3_commit_push.sql (1.57ms)9772026/10/01 07:33:44 goose: up to current file version: 39782026/10/01 07:33:44 goose: up to current file version: 39792026/10/01 07:33:44 OK 3_commit_push.sql (1.33ms)9802026/10/01 07:33:44 goose: up to current file version: 39812026/10/01 07:33:44 OK 3_commit_push.sql (1.45ms)9822026/10/01 07:33:44 goose: up to current file version: 39832026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.18ms)9842026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.95ms)9852026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.01ms)9862026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures9872026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.24ms)9882026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.47ms)9892026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.02ms)9902026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)9912026/10/01 07:33:44 OK 3_commit_push.sql (1.33ms)9922026/10/01 07:33:44 goose: up to current file version: 39932026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.86ms)9942026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.1ms)9952026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.76ms)9962026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.61ms)9972026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.86ms)9982026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.93ms)9992026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3ms)10002026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.22ms)10012026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010022026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.54ms)10032026/10/01 07:33:44 OK 20260905000000_add_claims.sql (5ms)10042026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.92ms)10052026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010062026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.87ms)10072026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010082026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.35ms)10092026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010102026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.31ms)10112026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010122026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.19ms)10132026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.17ms)10142026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.72ms)10152026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.31ms)10162026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.24ms)10172026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.61ms)10182026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.33ms)10192026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.66ms)10202026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010212026/10/01 07:33:44 OK 2_object_stats_trigger.sql (3.14ms)10222026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4.01ms)10232026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.65ms)10242026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.55ms)10252026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.85ms)10262026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010272026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (4.81ms)10282026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010292026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.62ms)10302026/10/01 07:33:44 OK 3_commit_push.sql (1.68ms)10312026/10/01 07:33:44 goose: up to current file version: 310322026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2.5ms)10332026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.19ms)10342026/10/01 07:33:44 OK 3_commit_push.sql (2.35ms)10352026/10/01 07:33:44 goose: up to current file version: 310362026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.08ms)10372026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010382026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.25ms)10392026/10/01 07:33:44 OK 3_commit_push.sql (2.15ms)10402026/10/01 07:33:44 goose: up to current file version: 310412026/10/01 07:33:44 OK 3_commit_push.sql (2.35ms)10422026/10/01 07:33:44 goose: up to current file version: 310432026/10/01 07:33:44 OK 20241026095416_initial_model.sql (13.39ms)10442026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.3ms)10452026/10/01 07:33:44 OK 3_commit_push.sql (2.68ms)10462026/10/01 07:33:44 goose: up to current file version: 310472026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.53ms)10482026/10/01 07:33:44 OK 1_commit_pending_closure.sql (1.43ms)10492026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.17ms)10502026/10/01 07:33:44 OK 2_object_stats_trigger.sql (968.15µs)10512026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)10522026/10/01 07:33:44 OK 3_commit_push.sql (1.45ms)10532026/10/01 07:33:44 goose: up to current file version: 310542026/10/01 07:33:44 OK 3_commit_push.sql (1.41ms)10552026/10/01 07:33:44 goose: up to current file version: 310562026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.77ms)10572026/10/01 07:33:44 OK 3_commit_push.sql (1.39ms)10582026/10/01 07:33:44 goose: up to current file version: 310592026/10/01 07:33:44 OK 3_commit_push.sql (1.22ms)10602026/10/01 07:33:44 goose: up to current file version: 310612026/10/01 07:33:44 OK 20251218171726_add_pins.sql (2.89ms)10622026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)10632026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.44ms)10642026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.18ms)10652026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.22ms)10662026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000010672026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.38ms)10682026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.39ms)10692026/10/01 07:33:44 OK 3_commit_push.sql (1.08ms)10702026/10/01 07:33:44 goose: up to current file version: 310712026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures10722026/10/01 07:33:44 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10732026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures1074--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.35s)1075=== CONT TestGCSweepSkipsPendingObjects1076--- PASS: TestService_Rustfstest (0.35s)1077=== CONT TestGCTaskStore_Fail1078--- PASS: TestGCTaskStore_Fail (0.00s)1079=== CONT TestPushDedupSurvivesConcurrentGC10802026-10-01 07:33:44.528 UTC [481] ERROR: relation "goose_db_version" does not exist at character 3610812026-10-01 07:33:44.528 UTC [481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026/10/01 07:33:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10832026/10/01 07:33:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10842026/10/01 07:33:44 INFO Aborted multipart uploads count=010852026/10/01 07:33:44 OK 20241026095416_initial_model.sql (16.76ms)10862026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures10872026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)10882026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.29ms)10892026/10/01 07:33:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10902026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)10912026/10/01 07:33:44 INFO Aborted multipart uploads count=110922026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.37ms)10932026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.29ms)10942026/10/01 07:33:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10952026-10-01 07:33:44.567 UTC [453] ERROR: Closure does not exist: id=110962026-10-01 07:33:44.567 UTC [453] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10972026-10-01 07:33:44.567 UTC [453] STATEMENT: -- name: CommitPendingClosure :exec1098 SELECT commit_pending_closure($1::bigint)1099 1100--- PASS: TestService_cleanupPendingClosuresHandler (0.40s)1101=== CONT TestGCTaskStore_PhaseUpdates1102--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1103=== CONT TestDeduplicatedObjectsRecordedAsPending11042026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.35ms)11052026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000011062026/10/01 07:33:44 INFO lead: acquired remote=192.0.2.1:123411072026/10/01 07:33:44 INFO lead: released remote=192.0.2.1:12341108--- PASS: TestLeadEndsOnShutdown (0.39s)1109=== CONT TestGCTaskStore_CompletedAllowsNewTask1110--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1111=== CONT TestReadProxyNarStreaming11122026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.56ms)11132026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.71ms)11142026/10/01 07:33:44 OK 3_commit_push.sql (1.3ms)11152026/10/01 07:33:44 goose: up to current file version: 311162026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures11172026-10-01 07:33:44.609 UTC [535] ERROR: relation "goose_db_version" does not exist at character 3611182026-10-01 07:33:44.609 UTC [535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11192026-10-01 07:33:44.610 UTC [541] ERROR: relation "goose_db_version" does not exist at character 3611202026-10-01 07:33:44.610 UTC [541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11212026/10/01 07:33:44 INFO lead: acquired remote=192.0.2.1:123411222026/10/01 07:33:44 OK 20241026095416_initial_model.sql (13.49ms)11232026/10/01 07:33:44 OK 20241026095416_initial_model.sql (14.73ms)1124=== NAME TestClientMultipleUploads1125 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3630155056/001/store/wm56as71kyi982xv1zdhyvys2rfxkqsx-test-file-0.txt11262026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (9.37ms)11272026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (9.56ms)11282026/10/01 07:33:44 OK 20251218171726_add_pins.sql (3.78ms)11292026/10/01 07:33:44 OK 20251218171726_add_pins.sql (3.28ms)11302026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)11312026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)11322026-10-01 07:33:44.650 UTC [578] ERROR: relation "goose_db_version" does not exist at character 3611332026-10-01 07:33:44.650 UTC [578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026-10-01 07:33:44.650 UTC [579] ERROR: relation "goose_db_version" does not exist at character 3611352026-10-01 07:33:44.650 UTC [579] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.77ms)11372026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.66ms)11382026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.18ms)11392026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.21ms)11402026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (1.89ms)11412026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000011422026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.1ms)11432026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000011442026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.2ms)11452026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.43ms)11462026/10/01 07:33:44 OK 2_object_stats_trigger.sql (2ms)11472026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.4ms)11482026/10/01 07:33:44 OK 3_commit_push.sql (1.2ms)11492026/10/01 07:33:44 goose: up to current file version: 311502026/10/01 07:33:44 OK 3_commit_push.sql (1.42ms)11512026/10/01 07:33:44 goose: up to current file version: 311522026/10/01 07:33:44 OK 20241026095416_initial_model.sql (10.33ms)11532026/10/01 07:33:44 OK 20241026095416_initial_model.sql (12.23ms)11542026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)11552026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)11562026/10/01 07:33:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1157--- PASS: TestService_AuthMiddleware (0.50s)1158=== CONT TestGCTaskStore_GetReturnsLatest1159=== NAME TestClientMultipleUploads1160 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3630155056/001/store/ipfcrnrlyxi76hamr0y3y3bi23gzzwd2-test-file-1.txt1161--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1162=== CONT TestCompletedNarNotReofferedAcrossClosures11632026/10/01 07:33:44 OK 20251218171726_add_pins.sql (3.06ms)11642026/10/01 07:33:44 OK 20251218171726_add_pins.sql (3.16ms)11652026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)11662026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)11672026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.35ms)11682026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.38ms)11692026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (1.8ms)11702026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (1.81ms)11712026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.15ms)11722026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000011732026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.55ms)11742026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000011752026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.05ms)11762026/10/01 07:33:44 OK 1_commit_pending_closure.sql (1.72ms)11772026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.05ms)11782026/10/01 07:33:44 OK 2_object_stats_trigger.sql (984.07µs)11792026/10/01 07:33:44 INFO Received push request method=POST path=/api/pushes11802026/10/01 07:33:44 OK 3_commit_push.sql (1.1ms)11812026/10/01 07:33:44 goose: up to current file version: 311822026/10/01 07:33:44 OK 3_commit_push.sql (1.05ms)11832026/10/01 07:33:44 goose: up to current file version: 311842026/10/01 07:33:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11852026/10/01 07:33:44 INFO Uploading 089ca0nwyzhynwfy8xrww7ylf42v97p3-shared-dep (136B)11862026/10/01 07:33:44 INFO Uploading j9fqrfsnmjf9drh5bcafilng1zx9v13h-b (208B)11872026/10/01 07:33:44 WARN Failed to register uploaded object key=7qylbwr2b5p0xcphz66pm3hg6mdxdhlb.ls error="server returned 404: 404 page not found\n"11882026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/127x81gal9qrvrwja58vq7qfrykj4z3mxlrlbca7x1xhhc5n7klh.nar.zst error="server returned 404: 404 page not found\n"11892026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11902026/10/01 07:33:44 WARN Failed to register uploaded object key=j9fqrfsnmjf9drh5bcafilng1zx9v13h.ls error="server returned 404: 404 page not found\n"11912026/10/01 07:33:44 WARN Failed to register uploaded object key=089ca0nwyzhynwfy8xrww7ylf42v97p3.ls error="server returned 404: 404 page not found\n"11922026/10/01 07:33:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11932026/10/01 07:33:44 INFO Signed narinfos id=1 count=311942026/10/01 07:33:44 INFO Uploading 3 narinfos11952026/10/01 07:33:44 WARN Failed to register uploaded object key=j9fqrfsnmjf9drh5bcafilng1zx9v13h.narinfo error="server returned 404: 404 page not found\n"11962026/10/01 07:33:44 WARN Failed to register uploaded object key=089ca0nwyzhynwfy8xrww7ylf42v97p3.narinfo error="server returned 404: 404 page not found\n"11972026/10/01 07:33:44 INFO Received complete push request method=POST path=/api/pushes/1/complete11982026/10/01 07:33:44 WARN Failed to register uploaded object key=7qylbwr2b5p0xcphz66pm3hg6mdxdhlb.narinfo error="server returned 404: 404 page not found\n"11992026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures12002026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures12012026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures1202=== NAME TestClientMultipleUploads1203 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3630155056/001/store/hh1vin5f02ppa9hdw8fn6ksydmdy13yr-test-file-2.txt12042026/10/01 07:33:44 INFO Upload complete. (67ms)1205=== NAME TestClientPushesUseOnePush1206 client_pushes_test.go:97: Retrieved narinfo from S3:1207 StorePath: /build/TestClientPushesUseOnePush359306705/001/store/089ca0nwyzhynwfy8xrww7ylf42v97p3-shared-dep1208 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1209 Compression: zstd1210 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821211 NarSize: 1361212 References: 1213 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1214 client_pushes_test.go:97: Retrieved narinfo from S3:1215 StorePath: /build/TestClientPushesUseOnePush359306705/001/store/7qylbwr2b5p0xcphz66pm3hg6mdxdhlb-a1216 URL: nar/127x81gal9qrvrwja58vq7qfrykj4z3mxlrlbca7x1xhhc5n7klh.nar.zst1217 Compression: zstd1218 NarHash: sha256:127x81gal9qrvrwja58vq7qfrykj4z3mxlrlbca7x1xhhc5n7klh1219 NarSize: 2081220 References: /build/TestClientPushesUseOnePush359306705/001/store/089ca0nwyzhynwfy8xrww7ylf42v97p3-shared-dep1221 CA: text:sha256:0ncl65fjixjg329cavq3ysv74r4hw55sj2d96y48iprkajl3g62s1222 client_pushes_test.go:97: Retrieved narinfo from S3:1223 StorePath: /build/TestClientPushesUseOnePush359306705/001/store/j9fqrfsnmjf9drh5bcafilng1zx9v13h-b1224 URL: nar/127x81gal9qrvrwja58vq7qfrykj4z3mxlrlbca7x1xhhc5n7klh.nar.zst1225 Compression: zstd1226 NarHash: sha256:127x81gal9qrvrwja58vq7qfrykj4z3mxlrlbca7x1xhhc5n7klh1227 NarSize: 2081228 References: /build/TestClientPushesUseOnePush359306705/001/store/089ca0nwyzhynwfy8xrww7ylf42v97p3-shared-dep1229 CA: text:sha256:0ncl65fjixjg329cavq3ysv74r4hw55sj2d96y48iprkajl3g62s1230--- PASS: TestClientPushesUseOnePush (0.56s)1231=== CONT TestGCTaskStore_GetEmpty1232--- PASS: TestGCTaskStore_GetEmpty (0.00s)1233=== CONT TestGCTaskStore_ConflictDifferentParams1234--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1235=== CONT TestGCTaskStore_DeduplicateSameParams1236--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1237=== CONT TestGCTaskStore_StartNew1238--- PASS: TestGCTaskStore_StartNew (0.00s)1239=== CONT TestGetExistingObjectsLocksRows12402026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures1241--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.57s)1242=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12432026-10-01 07:33:44.747 UTC [657] ERROR: relation "goose_db_version" does not exist at character 3612442026-10-01 07:33:44.747 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12452026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures12462026/10/01 07:33:44 OK 20241026095416_initial_model.sql (13.02ms)12472026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)12482026/10/01 07:33:44 OK 20251218171726_add_pins.sql (3.67ms)12492026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)12502026/10/01 07:33:44 INFO lead: released remote=192.0.2.1:123412512026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4ms)1252=== NAME TestClientWithDependencies1253 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1451118384/001/store/125fw6ap8im55zfhxvwfc912xm0mhjf3-test-script12542026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.46ms)12552026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.4ms)12562026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000012572026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.26ms)12582026/10/01 07:33:44 INFO Received push request method=POST path=/api/pushes12592026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.58ms)12602026/10/01 07:33:44 OK 3_commit_push.sql (1.42ms)12612026/10/01 07:33:44 goose: up to current file version: 312622026/10/01 07:33:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12632026/10/01 07:33:44 INFO Uploading hh1vin5f02ppa9hdw8fn6ksydmdy13yr-test-file-2.txt (160B)12642026/10/01 07:33:44 INFO Uploading ipfcrnrlyxi76hamr0y3y3bi23gzzwd2-test-file-1.txt (160B)12652026/10/01 07:33:44 INFO Uploading wm56as71kyi982xv1zdhyvys2rfxkqsx-test-file-0.txt (160B)12662026/10/01 07:33:44 INFO Aborted multipart uploads count=012672026/10/01 07:33:44 WARN Failed to register uploaded object key=wm56as71kyi982xv1zdhyvys2rfxkqsx.ls error="server returned 404: 404 page not found\n"12682026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12692026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12702026/10/01 07:33:44 WARN Failed to register uploaded object key=ipfcrnrlyxi76hamr0y3y3bi23gzzwd2.ls error="server returned 404: 404 page not found\n"12712026/10/01 07:33:44 WARN Failed to register uploaded object key=hh1vin5f02ppa9hdw8fn6ksydmdy13yr.ls error="server returned 404: 404 page not found\n"12722026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12732026/10/01 07:33:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12742026-10-01 07:33:44.804 UTC [717] ERROR: relation "goose_db_version" does not exist at character 3612752026-10-01 07:33:44.804 UTC [717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12762026/10/01 07:33:44 WARN Force mode enabled - objects will be deleted immediately without grace period12772026/10/01 07:33:44 INFO Signed narinfos id=1 count=312782026/10/01 07:33:44 INFO Uploading 3 narinfos12792026/10/01 07:33:44 WARN Failed to register uploaded object key=ipfcrnrlyxi76hamr0y3y3bi23gzzwd2.narinfo error="server returned 404: 404 page not found\n"12802026/10/01 07:33:44 WARN Failed to register uploaded object key=hh1vin5f02ppa9hdw8fn6ksydmdy13yr.narinfo error="server returned 404: 404 page not found\n"12812026/10/01 07:33:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12822026/10/01 07:33:44 WARN Failed to register uploaded object key=wm56as71kyi982xv1zdhyvys2rfxkqsx.narinfo error="server returned 404: 404 page not found\n"12832026/10/01 07:33:44 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=012842026/10/01 07:33:44 INFO Vacuumed table table=pending_closures12852026/10/01 07:33:44 INFO Vacuumed table table=pending_objects12862026/10/01 07:33:44 INFO Vacuumed table table=multipart_uploads12872026/10/01 07:33:44 INFO Vacuumed table table=closures12882026/10/01 07:33:44 INFO Vacuumed table table=objects12892026/10/01 07:33:44 INFO Upload complete. (65ms)1290=== NAME TestClientMultipleUploads1291 client_integration_test.go:369: Uploaded 3 paths in 101.584074ms1292=== NAME TestClientWithDependencies1293 client_integration_test.go:615: Found 1 dependencies (including self)12942026/10/01 07:33:44 INFO Aborted multipart uploads count=012952026/10/01 07:33:44 WARN Force mode enabled - objects will be deleted immediately without grace period12962026/10/01 07:33:44 OK 20241026095416_initial_model.sql (10.33ms)12972026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)12982026-10-01 07:33:44.824 UTC [735] ERROR: relation "goose_db_version" does not exist at character 3612992026-10-01 07:33:44.824 UTC [735] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1300--- PASS: TestClientMultipleUploads (0.65s)1301=== CONT TestIsValidUploadKey1302=== RUN TestIsValidUploadKey/narinfo1303=== PAUSE TestIsValidUploadKey/narinfo1304=== RUN TestIsValidUploadKey/nar_zst1305=== PAUSE TestIsValidUploadKey/nar_zst1306=== RUN TestIsValidUploadKey/nar_xz1307=== PAUSE TestIsValidUploadKey/nar_xz1308=== RUN TestIsValidUploadKey/nar_plain1309=== PAUSE TestIsValidUploadKey/nar_plain1310=== RUN TestIsValidUploadKey/listing1311=== PAUSE TestIsValidUploadKey/listing1312=== RUN TestIsValidUploadKey/build_log1313=== PAUSE TestIsValidUploadKey/build_log1314=== RUN TestIsValidUploadKey/build_log_home-manager_file1315=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1316=== RUN TestIsValidUploadKey/build_log_plus_in_name1317=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1318=== RUN TestIsValidUploadKey/build_log_question_mark1319=== PAUSE TestIsValidUploadKey/build_log_question_mark1320=== RUN TestIsValidUploadKey/build_log_equals1321=== PAUSE TestIsValidUploadKey/build_log_equals1322=== RUN TestIsValidUploadKey/realisation1323=== PAUSE TestIsValidUploadKey/realisation1324=== RUN TestIsValidUploadKey/realisation_plus_in_output1325=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1326=== RUN TestIsValidUploadKey/nix-cache-info1327=== PAUSE TestIsValidUploadKey/nix-cache-info1328=== RUN TestIsValidUploadKey/index.html1329=== PAUSE TestIsValidUploadKey/index.html1330=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1331=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1332=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1333=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1334=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1335=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1336=== RUN TestIsValidUploadKey/traversal1337=== PAUSE TestIsValidUploadKey/traversal1338=== RUN TestIsValidUploadKey/traversal_nar1339=== PAUSE TestIsValidUploadKey/traversal_nar1340=== RUN TestIsValidUploadKey/absolute1341=== PAUSE TestIsValidUploadKey/absolute1342=== RUN TestIsValidUploadKey/empty_key1343=== PAUSE TestIsValidUploadKey/empty_key1344=== RUN TestIsValidUploadKey/unknown_type1345=== PAUSE TestIsValidUploadKey/unknown_type1346=== CONT TestRedundantMultipartUpload13472026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.12ms)13482026/10/01 07:33:44 INFO lead: acquired remote=192.0.2.1:123413492026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)13502026/10/01 07:33:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=013512026/10/01 07:33:44 INFO Vacuumed table table=pending_closures13522026/10/01 07:33:44 INFO Vacuumed table table=pending_objects13532026/10/01 07:33:44 INFO Vacuumed table table=multipart_uploads13542026/10/01 07:33:44 INFO Vacuumed table table=closures13552026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.76ms)13562026/10/01 07:33:44 INFO lead: released remote=192.0.2.1:123413572026/10/01 07:33:44 INFO Vacuumed table table=objects1358--- PASS: TestLeadElectsOneAndHandsOver (0.66s)1359=== CONT TestReadRedirectKeepsNarinfoProxied1360--- PASS: TestSweepSkipsRowsLockedByPush (0.66s)1361=== CONT TestReadRedirectNar13622026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (1.85ms)13632026/10/01 07:33:44 OK 20241026095416_initial_model.sql (8.13ms)13642026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.33ms)13652026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000013662026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)13672026/10/01 07:33:44 INFO Aborted multipart uploads count=013682026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.05ms)13692026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.54ms)13702026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.35ms)13712026/10/01 07:33:44 WARN Force mode enabled - objects will be deleted immediately without grace period13722026/10/01 07:33:44 OK 3_commit_push.sql (1.68ms)13732026/10/01 07:33:44 goose: up to current file version: 313742026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)13752026/10/01 07:33:44 OK 20260905000000_add_claims.sql (10.29ms)13762026/10/01 07:33:44 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13772026/10/01 07:33:44 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13782026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.17ms)1379--- PASS: TestFailedS3DeleteKeepsTombstone (0.63s)1380=== CONT TestGCMetrics13812026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (2.72ms)13822026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200001383=== NAME TestClientIntegration1384 client_integration_test.go:286: Created store path: /build/TestClientIntegration2249288313/002/store/ajgcfgccpryzyig7s4xa2ixyc131y56c-test-file.txt13852026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.65ms)13862026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.5ms)13872026/10/01 07:33:44 OK 3_commit_push.sql (1.48ms)13882026/10/01 07:33:44 goose: up to current file version: 31389--- PASS: TestGCBugBareHashReferences (0.70s)1390=== CONT TestReadProxyDisabled1391=== NAME TestPinProtectsFromGC1392 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1046110214/001/store/s8z8fd0ir03ai6cqpz96n7wxyxnhh896-pinned-file.txt1393 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1046110214/001/store/98in9c9yvb7acwzvdnj2ykcs7pv797sn-unpinned-file.txt13942026/10/01 07:33:44 INFO Received push request method=POST path=/api/pushes13952026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures13962026/10/01 07:33:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13972026/10/01 07:33:44 INFO Uploading 125fw6ap8im55zfhxvwfc912xm0mhjf3-test-script (136B)1398--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.72s)1399=== CONT TestReadProxyRootRedirectsToIndexHTML14002026/10/01 07:33:44 WARN Failed to register uploaded object key=125fw6ap8im55zfhxvwfc912xm0mhjf3.ls error="server returned 404: 404 page not found\n"14012026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14022026/10/01 07:33:44 WARN Failed to register uploaded object key=log/qvwb3qa2qapmzrsk48q154zfrbigwk6y-test-script.drv error="server returned 404: 404 page not found\n"14032026/10/01 07:33:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14042026/10/01 07:33:44 INFO Signed narinfos id=1 count=114052026/10/01 07:33:44 INFO Uploading 1 narinfos14062026/10/01 07:33:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14072026/10/01 07:33:44 WARN Failed to register uploaded object key=125fw6ap8im55zfhxvwfc912xm0mhjf3.narinfo error="server returned 404: 404 page not found\n"14082026-10-01 07:33:44.909 UTC [874] ERROR: relation "goose_db_version" does not exist at character 3614092026-10-01 07:33:44.909 UTC [874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14102026-10-01 07:33:44.917 UTC [909] ERROR: relation "goose_db_version" does not exist at character 3614112026-10-01 07:33:44.917 UTC [909] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14122026-10-01 07:33:44.918 UTC [910] ERROR: relation "goose_db_version" does not exist at character 3614132026-10-01 07:33:44.918 UTC [910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14142026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures14152026/10/01 07:33:44 INFO Upload complete. (71ms)1416=== NAME TestClientWithDependencies1417 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1451118384/001/store) requires matching store prefix14182026/10/01 07:33:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1419--- PASS: TestClientWithDependencies (0.76s)1420=== CONT TestMultipartCleanup1421--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.63s)1422=== CONT TestPush_SignsNarinfosOfItsPendingObjects14232026/10/01 07:33:44 OK 20241026095416_initial_model.sql (14.15ms)14242026/10/01 07:33:44 OK 20241026095416_initial_model.sql (14.27ms)14252026/10/01 07:33:44 OK 20241026095416_initial_model.sql (15.18ms)14262026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)14272026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)14282026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)14292026/10/01 07:33:44 INFO Received push request method=POST path=/api/pushes14302026/10/01 07:33:44 INFO Received push request method=POST path=/api/pushes14312026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.64ms)14322026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.79ms)14332026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.88ms)14342026-10-01 07:33:44.950 UTC [999] ERROR: relation "goose_db_version" does not exist at character 3614352026-10-01 07:33:44.950 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14362026/10/01 07:33:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14372026/10/01 07:33:44 INFO Uploading ajgcfgccpryzyig7s4xa2ixyc131y56c-test-file.txt (152B)14382026/10/01 07:33:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTY1Mzc0OGUtZjdiNi00NmM4LWI2NTAtZDUwYzU1YzI1ZmZmLjgwMjRjOWI3LTBkZjYtNDM3Yy1hNDg4LTVmM2FmZmJhYjUwZXgxNzkwODQwMDI0NjE2NjgxODYx parts=1014392026/10/01 07:33:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14402026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)14412026/10/01 07:33:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14422026/10/01 07:33:44 INFO Uploading s8z8fd0ir03ai6cqpz96n7wxyxnhh896-pinned-file.txt (128B)14432026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)14442026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)14452026/10/01 07:33:44 INFO Completed upload id=114462026/10/01 07:33:44 WARN Failed to register uploaded object key=ajgcfgccpryzyig7s4xa2ixyc131y56c.ls error="server returned 404: 404 page not found\n"14472026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.32ms)14482026/10/01 07:33:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14492026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14502026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures14512026/10/01 07:33:44 OK 20260905000000_add_claims.sql (3.72ms)14522026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.19ms)14532026/10/01 07:33:44 INFO Signed narinfos id=1 count=114542026/10/01 07:33:44 INFO Uploading 1 narinfos14552026/10/01 07:33:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14562026/10/01 07:33:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14572026-10-01 07:33:44.958 UTC [1018] ERROR: relation "goose_db_version" does not exist at character 3614582026-10-01 07:33:44.958 UTC [1018] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14592026/10/01 07:33:44 WARN Failed to register uploaded object key=s8z8fd0ir03ai6cqpz96n7wxyxnhh896.ls error="server returned 404: 404 page not found\n"14602026/10/01 07:33:44 INFO Signed narinfos id=1 count=114612026/10/01 07:33:44 INFO Uploading 1 narinfos14622026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (4ms)14632026/10/01 07:33:44 INFO Received uploads request method=POST path=/api/pending_closures14642026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.49ms)14652026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (3.57ms)14662026/10/01 07:33:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14672026/10/01 07:33:44 WARN Failed to register uploaded object key=ajgcfgccpryzyig7s4xa2ixyc131y56c.narinfo error="server returned 404: 404 page not found\n"14682026/10/01 07:33:44 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14692026/10/01 07:33:44 WARN Found objects in DB but missing from S3, will re-upload count=114702026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.18ms)14712026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000014722026/10/01 07:33:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14732026/10/01 07:33:44 WARN Failed to register uploaded object key=s8z8fd0ir03ai6cqpz96n7wxyxnhh896.narinfo error="server returned 404: 404 page not found\n"14742026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.59ms)14752026/10/01 07:33:44 goose: successfully migrated database to version: 2026092312000014762026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (3.51ms)14772026/10/01 07:33:44 goose: successfully migrated database to version: 202609231200001478--- PASS: TestService_verifyS3Integrity (0.79s)1479=== CONT TestReadProxyConditionalGet14802026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.94ms)14812026/10/01 07:33:44 OK 1_commit_pending_closure.sql (2.88ms)14822026/10/01 07:33:44 OK 1_commit_pending_closure.sql (3.06ms)14832026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.65ms)14842026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.68ms)14852026/10/01 07:33:44 OK 2_object_stats_trigger.sql (1.79ms)14862026/10/01 07:33:44 OK 3_commit_push.sql (1.63ms)14872026/10/01 07:33:44 goose: up to current file version: 314882026/10/01 07:33:44 INFO Upload complete. (67ms)14892026/10/01 07:33:44 INFO Upload complete. (61ms)14902026/10/01 07:33:44 OK 3_commit_push.sql (1.7ms)14912026/10/01 07:33:44 goose: up to current file version: 314922026/10/01 07:33:44 OK 3_commit_push.sql (1.64ms)14932026/10/01 07:33:44 goose: up to current file version: 314942026/10/01 07:33:44 OK 20241026095416_initial_model.sql (12.39ms)14952026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)14962026-10-01 07:33:44.976 UTC [1024] ERROR: relation "goose_db_version" does not exist at character 3614972026-10-01 07:33:44.976 UTC [1024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14982026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.08ms)14992026/10/01 07:33:44 OK 20241026095416_initial_model.sql (13.81ms)15002026/10/01 07:33:44 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)15012026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)15022026/10/01 07:33:44 OK 20251218171726_add_pins.sql (4.59ms)15032026/10/01 07:33:44 OK 20260905000000_add_claims.sql (4.57ms)15042026/10/01 07:33:44 OK 20260920000000_drop_claims.sql (2.9ms)15052026/10/01 07:33:44 INFO Aborted multipart uploads count=015062026/10/01 07:33:44 WARN Force mode enabled - objects will be deleted immediately without grace period15072026/10/01 07:33:44 INFO Received push request method=POST path=/api/pushes15082026/10/01 07:33:44 OK 20260628120000_add_object_size_and_stats.sql (13.68ms)15092026/10/01 07:33:44 OK 20241026095416_initial_model.sql (15.98ms)15102026/10/01 07:33:44 OK 20260923120000_add_pushes.sql (9.91ms)15112026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000015122026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)15132026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.5ms)15142026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.35ms)15152026/10/01 07:33:45 OK 2_object_stats_trigger.sql (2.36ms)15162026/10/01 07:33:45 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15172026/10/01 07:33:45 INFO Uploading yx9yrcvp7apjw91fj9r6yiy0va07v6ab-shared-dep (136B)15182026/10/01 07:33:45 INFO Uploading jzrhrhaykhaqynb7r7xvc95w2sg6ck11-top (224B)15192026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.71ms)15202026/10/01 07:33:45 OK 3_commit_push.sql (2.55ms)15212026/10/01 07:33:45 goose: up to current file version: 315222026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.66ms)15232026/10/01 07:33:45 INFO All 1 paths already cached15242026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.67ms)15252026/10/01 07:33:45 goose: successfully migrated database to version: 202609231200001526=== NAME TestClientIntegration1527 client_integration_test.go:312: Retrieved narinfo from S3:1528 StorePath: /build/TestClientIntegration2249288313/002/store/ajgcfgccpryzyig7s4xa2ixyc131y56c-test-file.txt1529 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1530 Compression: zstd1531 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11532 NarSize: 1521533 References: 1534 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115352026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)15362026/10/01 07:33:45 WARN Failed to register uploaded object key=jzrhrhaykhaqynb7r7xvc95w2sg6ck11.ls error="server returned 404: 404 page not found\n"15372026/10/01 07:33:45 WARN Failed to register uploaded object key=yx9yrcvp7apjw91fj9r6yiy0va07v6ab.ls error="server returned 404: 404 page not found\n"15382026/10/01 07:33:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15392026/10/01 07:33:45 WARN Failed to register uploaded object key=nar/0ilj845f6khy9wbr8i0chygzaz2gcvzh3rqhjdj752x9vf1mgzb4.nar.zst error="server returned 404: 404 page not found\n"15402026/10/01 07:33:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15412026/10/01 07:33:45 INFO Signed narinfos id=1 count=215422026-10-01 07:33:45.012 UTC [1095] ERROR: relation "goose_db_version" does not exist at character 3615432026-10-01 07:33:45.012 UTC [1095] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15442026/10/01 07:33:45 INFO Uploading 2 narinfos15452026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.52ms)15462026/10/01 07:33:45 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=01547 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1548 client_integration_test.go:313: Decompressed .ls content (64 bytes):1549 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}15502026/10/01 07:33:45 INFO Vacuumed table table=pending_closures1551 client_integration_test.go:316: Testing garbage collection...15522026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.81ms)15532026/10/01 07:33:45 INFO Vacuumed table table=pending_objects15542026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads15552026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.29ms)15562026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/01 07:33:45 INFO Vacuumed table table=closures15582026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures15592026/10/01 07:33:45 OK 3_commit_push.sql (1.83ms)15602026/10/01 07:33:45 goose: up to current file version: 315612026/10/01 07:33:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15622026/10/01 07:33:45 WARN Failed to register uploaded object key=jzrhrhaykhaqynb7r7xvc95w2sg6ck11.narinfo error="server returned 404: 404 page not found\n"15632026/10/01 07:33:45 WARN Failed to register uploaded object key=yx9yrcvp7apjw91fj9r6yiy0va07v6ab.narinfo error="server returned 404: 404 page not found\n"15642026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.58ms)15652026/10/01 07:33:45 INFO Vacuumed table table=objects1566--- PASS: TestGCSweepDeliversEachKeyOnce (0.57s)1567=== CONT TestReadProxyNarinfoAlreadyDecompressed15682026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.58ms)15692026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000015702026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.19ms)15712026-10-01 07:33:45.024 UTC [1100] ERROR: relation "goose_db_version" does not exist at character 3615722026-10-01 07:33:45.024 UTC [1100] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/10/01 07:33:45 INFO Upload complete. (67ms)15742026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.92ms)1575=== NAME TestClientSharedPathCommittedMidPush1576 client_integration_test.go:680: Retrieved narinfo from S3:1577 StorePath: /build/TestClientSharedPathCommittedMidPush864807539/001/store/yx9yrcvp7apjw91fj9r6yiy0va07v6ab-shared-dep1578 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1579 Compression: zstd1580 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821581 NarSize: 1361582 References: 1583 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15842026/10/01 07:33:45 OK 3_commit_push.sql (1.36ms)15852026/10/01 07:33:45 goose: up to current file version: 31586 client_integration_test.go:680: Retrieved narinfo from S3:1587 StorePath: /build/TestClientSharedPathCommittedMidPush864807539/001/store/jzrhrhaykhaqynb7r7xvc95w2sg6ck11-top1588 URL: nar/0ilj845f6khy9wbr8i0chygzaz2gcvzh3rqhjdj752x9vf1mgzb4.nar.zst1589 Compression: zstd1590 NarHash: sha256:0ilj845f6khy9wbr8i0chygzaz2gcvzh3rqhjdj752x9vf1mgzb41591 NarSize: 2241592 References: /build/TestClientSharedPathCommittedMidPush864807539/001/store/yx9yrcvp7apjw91fj9r6yiy0va07v6ab-shared-dep1593 CA: text:sha256:0yfrpxq6aqj1azg1l0gr1xlzyy4bn36xc6wqwvy57gcky1793xx315942026/10/01 07:33:45 OK 20241026095416_initial_model.sql (12.87ms)1595--- PASS: TestClientSharedPathCommittedMidPush (0.86s)1596=== CONT TestPush_RejectsBadRequests15972026/10/01 07:33:45 INFO Aborted multipart uploads count=015982026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)15992026/10/01 07:33:45 WARN Force mode enabled - objects will be deleted immediately without grace period16002026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes16012026/10/01 07:33:45 OK 20251218171726_add_pins.sql (5.03ms)16022026/10/01 07:33:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16032026/10/01 07:33:45 INFO Uploading 98in9c9yvb7acwzvdnj2ykcs7pv797sn-unpinned-file.txt (128B)16042026/10/01 07:33:45 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=016052026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.34ms)1606--- PASS: TestReadProxyNarStreaming (0.47s)16072026-10-01 07:33:45.044 UTC [1140] ERROR: relation "goose_db_version" does not exist at character 3616082026-10-01 07:33:45.044 UTC [1140] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1609=== CONT TestReadProxyHead16102026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)16112026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)16122026/10/01 07:33:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures16132026/10/01 07:33:45 INFO Vacuumed table table=pending_closures16142026/10/01 07:33:45 INFO Garbage collection started16152026/10/01 07:33:45 WARN Failed to register uploaded object key=98in9c9yvb7acwzvdnj2ykcs7pv797sn.ls error="server returned 404: 404 page not found\n"16162026/10/01 07:33:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16172026/10/01 07:33:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16182026/10/01 07:33:45 INFO Signed narinfos id=2 count=116192026/10/01 07:33:45 INFO Uploading 1 narinfos16202026/10/01 07:33:45 INFO Vacuumed table table=pending_objects16212026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads16222026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.49ms)16232026/10/01 07:33:45 INFO Vacuumed table table=closures16242026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.86ms)16252026/10/01 07:33:45 INFO Received complete push request method=POST path=/api/pushes/2/complete16262026/10/01 07:33:45 WARN Failed to register uploaded object key=98in9c9yvb7acwzvdnj2ykcs7pv797sn.narinfo error="server returned 404: 404 page not found\n"16272026/10/01 07:33:45 INFO Vacuumed table table=objects16282026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.45ms)16292026/10/01 07:33:45 INFO Upload complete. (47ms)16302026/10/01 07:33:45 INFO Aborted multipart uploads count=016312026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.78ms)16322026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.17ms)16332026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000016342026/10/01 07:33:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16352026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.53ms)1636--- PASS: TestGCSweepSkipsPendingObjects (0.54s)1637=== CONT TestCreatePin_ReservedPins16382026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.16ms)16392026/10/01 07:33:45 WARN Force mode enabled - objects will be deleted immediately without grace period16402026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.71ms)16412026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.26ms)16422026/10/01 07:33:45 OK 3_commit_push.sql (2.29ms)16432026/10/01 07:33:45 goose: up to current file version: 316442026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.23ms)16452026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures16462026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.62ms)16472026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000016482026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)16492026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.74ms)16502026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.93ms)16512026/10/01 07:33:45 OK 2_object_stats_trigger.sql (2.26ms)1652--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.50s)1653=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16542026/10/01 07:33:45 OK 3_commit_push.sql (1.99ms)16552026/10/01 07:33:45 goose: up to current file version: 316562026/10/01 07:33:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTY1Mzc0OGUtZjdiNi00NmM4LWI2NTAtZDUwYzU1YzI1ZmZmLmNmNDE1M2EyLTZhMTAtNGFlOS04ODI5LTVkN2UzYzU2MTY0YngxNzkwODQwMDI0NzIxNTQ1MDA1 parts=1016572026/10/01 07:33:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16582026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)16592026/10/01 07:33:45 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=016602026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures16612026/10/01 07:33:45 INFO Completed upload id=116622026/10/01 07:33:45 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016632026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.28ms)16642026/10/01 07:33:45 INFO Vacuumed table table=pending_closures16652026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures16662026/10/01 07:33:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures16672026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.69ms)16682026/10/01 07:33:45 INFO Vacuumed table table=pending_objects16692026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures16702026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads16712026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures16722026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.56ms)16732026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000016742026/10/01 07:33:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16752026/10/01 07:33:45 INFO Uploading znfvc8xyigyhnhkxkig4n307ghb2z5jx-a (216B)16762026/10/01 07:33:45 INFO Uploading gk2cxkxz44v43ca3iaw6xxzz903zy8sl-shared-dep (136B)16772026/10/01 07:33:45 INFO Vacuumed table table=closures16782026/10/01 07:33:45 INFO Aborted multipart uploads count=016792026/10/01 07:33:45 INFO Received create pin request method=POST path=/api/pins/myapp16802026/10/01 07:33:45 INFO Aborted multipart uploads count=016812026/10/01 07:33:45 WARN Failed to register uploaded object key=alvwhj64m9izfxnqzx4737225fbkb8wx.ls error="server returned 404: 404 page not found\n"16822026/10/01 07:33:45 WARN Failed to register uploaded object key=gk2cxkxz44v43ca3iaw6xxzz903zy8sl.ls error="server returned 404: 404 page not found\n"16832026/10/01 07:33:45 WARN Failed to register uploaded object key=znfvc8xyigyhnhkxkig4n307ghb2z5jx.ls error="server returned 404: 404 page not found\n"16842026/10/01 07:33:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16852026/10/01 07:33:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16862026/10/01 07:33:45 WARN Failed to register uploaded object key=nar/1x9igiq29bnk18hqhnvprxspp4hl0ma7pmw8164lgd12lr5i5nly.nar.zst error="server returned 404: 404 page not found\n"16872026/10/01 07:33:45 INFO Signed narinfos id=1 count=216882026/10/01 07:33:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16892026/10/01 07:33:45 INFO Signed narinfos id=2 count=216902026/10/01 07:33:45 INFO Uploading 4 narinfos16912026/10/01 07:33:45 OK 1_commit_pending_closure.sql (8.39ms)16922026/10/01 07:33:45 INFO Vacuumed table table=objects16932026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.96ms)16942026/10/01 07:33:45 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1046110214/001/store/s8z8fd0ir03ai6cqpz96n7wxyxnhh896-pinned-file.txt narinfo_key=s8z8fd0ir03ai6cqpz96n7wxyxnhh896.narinfo16952026/10/01 07:33:45 WARN Failed to register uploaded object key=alvwhj64m9izfxnqzx4737225fbkb8wx.narinfo error="server returned 404: 404 page not found\n"16962026/10/01 07:33:45 WARN Failed to register uploaded object key=znfvc8xyigyhnhkxkig4n307ghb2z5jx.narinfo error="server returned 404: 404 page not found\n"16972026/10/01 07:33:45 WARN Failed to register uploaded object key=gk2cxkxz44v43ca3iaw6xxzz903zy8sl.narinfo error="server returned 404: 404 page not found\n"16982026/10/01 07:33:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures16992026/10/01 07:33:45 OK 3_commit_push.sql (1.7ms)17002026/10/01 07:33:45 goose: up to current file version: 317012026/10/01 07:33:45 INFO Garbage collection started17022026/10/01 07:33:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17032026/10/01 07:33:45 WARN Failed to register uploaded object key=gk2cxkxz44v43ca3iaw6xxzz903zy8sl.narinfo error="server returned 404: 404 page not found\n"17042026/10/01 07:33:45 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=017052026/10/01 07:33:45 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=017062026/10/01 07:33:45 INFO Vacuumed table table=pending_closures17072026/10/01 07:33:45 INFO Vacuumed table table=pending_closures17082026/10/01 07:33:45 INFO Vacuumed table table=pending_objects17092026/10/01 07:33:45 INFO Completed upload id=217102026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads17112026/10/01 07:33:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17122026/10/01 07:33:45 INFO Vacuumed table table=pending_objects17132026-10-01 07:33:45.109 UTC [1202] ERROR: relation "goose_db_version" does not exist at character 3617142026-10-01 07:33:45.109 UTC [1202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17152026/10/01 07:33:45 INFO Completed upload id=117162026/10/01 07:33:45 INFO Aborted multipart uploads count=017172026/10/01 07:33:45 INFO Upload complete. (81ms)17182026/10/01 07:33:45 INFO Vacuumed table table=closures17192026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads1720=== NAME TestClientFallsBackToClosures1721 client_pushes_test.go:112: Retrieved narinfo from S3:1722 StorePath: /build/TestClientFallsBackToClosures3780684900/001/store/gk2cxkxz44v43ca3iaw6xxzz903zy8sl-shared-dep1723 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1724 Compression: zstd1725 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821726 NarSize: 1361727 References: 1728 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17292026/10/01 07:33:45 INFO Vacuumed table table=objects17302026/10/01 07:33:45 WARN Force mode enabled - objects will be deleted immediately without grace period17312026/10/01 07:33:45 INFO Vacuumed table table=closures1732 client_pushes_test.go:112: Retrieved narinfo from S3:1733 StorePath: /build/TestClientFallsBackToClosures3780684900/001/store/znfvc8xyigyhnhkxkig4n307ghb2z5jx-a1734 URL: nar/1x9igiq29bnk18hqhnvprxspp4hl0ma7pmw8164lgd12lr5i5nly.nar.zst1735 Compression: zstd1736 NarHash: sha256:1x9igiq29bnk18hqhnvprxspp4hl0ma7pmw8164lgd12lr5i5nly1737 NarSize: 2161738 References: /build/TestClientFallsBackToClosures3780684900/001/store/gk2cxkxz44v43ca3iaw6xxzz903zy8sl-shared-dep1739 CA: text:sha256:0awj8ki750m523sbwi73hz271i5jh2ypg564f5fk0k2ni3jlhx6317402026/10/01 07:33:45 INFO Aborted multipart uploads count=017412026/10/01 07:33:45 INFO Vacuumed table table=objects17422026/10/01 07:33:45 WARN Force mode enabled - objects will be deleted immediately without grace period1743 client_pushes_test.go:112: Retrieved narinfo from S3:1744 StorePath: /build/TestClientFallsBackToClosures3780684900/001/store/alvwhj64m9izfxnqzx4737225fbkb8wx-b1745 URL: nar/1x9igiq29bnk18hqhnvprxspp4hl0ma7pmw8164lgd12lr5i5nly.nar.zst1746 Compression: zstd1747 NarHash: sha256:1x9igiq29bnk18hqhnvprxspp4hl0ma7pmw8164lgd12lr5i5nly1748 NarSize: 2161749 References: /build/TestClientFallsBackToClosures3780684900/001/store/gk2cxkxz44v43ca3iaw6xxzz903zy8sl-shared-dep1750 CA: text:sha256:0awj8ki750m523sbwi73hz271i5jh2ypg564f5fk0k2ni3jlhx6317512026/10/01 07:33:45 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=017522026/10/01 07:33:45 INFO Vacuumed table table=pending_closures1753--- PASS: TestClientFallsBackToClosures (0.95s)17542026/10/01 07:33:45 INFO Vacuumed table table=pending_objects1755=== CONT TestReadProxyInvalidPath17562026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads1757--- PASS: TestGetExistingObjectsLocksRows (0.40s)1758=== CONT TestOrphanedObjectsGCStressTest17592026-10-01 07:33:45.127 UTC [1205] ERROR: relation "goose_db_version" does not exist at character 3617602026-10-01 07:33:45.127 UTC [1205] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1761--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.88s)1762=== CONT TestPush_CompleteCommitsEveryRoot17632026/10/01 07:33:45 INFO Vacuumed table table=closures17642026/10/01 07:33:45 INFO Vacuumed table table=objects17652026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.51ms)1766--- PASS: TestPushDedupSurvivesConcurrentGC (0.61s)1767=== CONT TestReadProxy40417682026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)17692026/10/01 07:33:45 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=017702026-10-01 07:33:45.133 UTC [1207] ERROR: relation "goose_db_version" does not exist at character 3617712026-10-01 07:33:45.133 UTC [1207] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17722026/10/01 07:33:45 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017732026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures1774--- PASS: TestService_createPendingClosureHandler (0.96s)1775=== CONT TestOrphanedObjectsGC17762026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.13ms)17772026/10/01 07:33:45 INFO Vacuumed table table=pending_closures17782026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)17792026/10/01 07:33:45 INFO Vacuumed table table=pending_objects17802026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads17812026/10/01 07:33:45 INFO Vacuumed table table=closures17822026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.43ms)17832026/10/01 07:33:45 INFO Vacuumed table table=objects17842026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.29ms)17852026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.48ms)17862026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)17872026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (4.21ms)17882026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000017892026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.24ms)17902026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.13ms)17912026/10/01 07:33:45 OK 1_commit_pending_closure.sql (3.31ms)17922026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)17932026-10-01 07:33:45.155 UTC [1217] ERROR: relation "goose_db_version" does not exist at character 3617942026-10-01 07:33:45.155 UTC [1217] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17952026/10/01 07:33:45 OK 2_object_stats_trigger.sql (2.05ms)17962026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)17972026/10/01 07:33:45 OK 3_commit_push.sql (2.27ms)17982026/10/01 07:33:45 goose: up to current file version: 317992026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.22ms)18002026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.37ms)18012026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)18022026/10/01 07:33:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1803--- PASS: TestReadRedirectNar (0.33s)1804=== CONT TestPush_OverlappingRootsStoreOneRowPerKey18052026/10/01 07:33:45 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTY1Mzc0OGUtZjdiNi00NmM4LWI2NTAtZDUwYzU1YzI1ZmZmLmQ0MmU0ZDI5LWNlMWQtNGQ0OC1hMTJlLWU5MDU0NWEyYTQ2OHgxNzkwODQwMDI1MTQyMTY3Mzg318062026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (9.24ms)18072026/10/01 07:33:45 OK 20260905000000_add_claims.sql (9.07ms)18082026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.42ms)18092026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.49ms)18102026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000018112026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.09ms)18122026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)18132026/10/01 07:33:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTY1Mzc0OGUtZjdiNi00NmM4LWI2NTAtZDUwYzU1YzI1ZmZmLmQ0MmU0ZDI5LWNlMWQtNGQ0OC1hMTJlLWU5MDU0NWEyYTQ2OHgxNzkwODQwMDI1MTQyMTY3Mzg3 parts=118142026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.46ms)18152026/10/01 07:33:45 goose: successfully migrated database to version: 202609231200001816--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.43s)1817=== CONT TestObjectStatsTrigger18182026/10/01 07:33:45 OK 1_commit_pending_closure.sql (3.09ms)18192026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.81ms)18202026/10/01 07:33:45 OK 1_commit_pending_closure.sql (1.96ms)18212026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.45ms)18222026/10/01 07:33:45 OK 3_commit_push.sql (1.45ms)18232026/10/01 07:33:45 goose: up to current file version: 318242026/10/01 07:33:45 OK 2_object_stats_trigger.sql (2.54ms)18252026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)18262026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures18272026/10/01 07:33:45 OK 3_commit_push.sql (2.1ms)18282026/10/01 07:33:45 goose: up to current file version: 318292026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.14ms)18302026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.02ms)18312026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.58ms)18322026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000018332026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.42ms)18342026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.69ms)18352026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures18362026/10/01 07:33:45 OK 3_commit_push.sql (1.58ms)18372026/10/01 07:33:45 goose: up to current file version: 318382026/10/01 07:33:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39183/oidc18392026-10-01 07:33:45.211 UTC [1222] ERROR: relation "goose_db_version" does not exist at character 3618402026-10-01 07:33:45.211 UTC [1222] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18412026-10-01 07:33:45.216 UTC [1224] ERROR: relation "goose_db_version" does not exist at character 3618422026-10-01 07:33:45.216 UTC [1224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18432026-10-01 07:33:45.219 UTC [1225] ERROR: relation "goose_db_version" does not exist at character 3618442026-10-01 07:33:45.219 UTC [1225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18452026-10-01 07:33:45.220 UTC [1227] ERROR: relation "goose_db_version" does not exist at character 3618462026-10-01 07:33:45.220 UTC [1227] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18472026-10-01 07:33:45.220 UTC [1228] ERROR: relation "goose_db_version" does not exist at character 3618482026-10-01 07:33:45.220 UTC [1228] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1849--- PASS: TestReadRedirectKeepsNarinfoProxied (0.39s)1850=== CONT TestReadRedirectUsesPublicS3URL18512026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.8ms)18522026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)18532026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.33ms)18542026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.34ms)18552026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)18562026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.49ms)18572026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.28ms)18582026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)18592026/10/01 07:33:45 OK 20241026095416_initial_model.sql (12.84ms)18602026/10/01 07:33:45 INFO Aborted multipart uploads count=018612026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)18622026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)18632026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)18642026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.8ms)18652026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.69ms)18662026/10/01 07:33:45 WARN Force mode enabled - objects will be deleted immediately without grace period18672026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.48ms)18682026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.32ms)18692026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.35ms)18702026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)18712026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.66ms)18722026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)18732026/10/01 07:33:45 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=018742026/10/01 07:33:45 INFO Vacuumed table table=pending_closures18752026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)18762026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.04ms)18772026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000018782026/10/01 07:33:45 INFO Vacuumed table table=pending_objects18792026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads18802026/10/01 07:33:45 INFO Vacuumed table table=closures18812026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)18822026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.9ms)18832026/10/01 07:33:45 INFO Vacuumed table table=objects18842026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.21ms)18852026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.52ms)18862026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.33ms)18872026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.13ms)1888--- PASS: TestGCMetrics (0.39s)1889=== CONT TestReadProxyRangeRequest18902026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.65ms)18912026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.91ms)18922026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.94ms)18932026/10/01 07:33:45 OK 3_commit_push.sql (1.38ms)18942026/10/01 07:33:45 goose: up to current file version: 318952026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.75ms)18962026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.14ms)18972026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000018982026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.98ms)18992026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000019002026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.1ms)19012026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.54ms)19022026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000019032026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.58ms)19042026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.49ms)1905--- PASS: TestReadProxyDisabled (0.38s)1906=== CONT TestIsValidCachePath1907=== RUN TestIsValidCachePath/narinfo1908=== PAUSE TestIsValidCachePath/narinfo1909=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1910=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1911=== RUN TestIsValidCachePath/nar_zst1912=== PAUSE TestIsValidCachePath/nar_zst1913=== RUN TestIsValidCachePath/nar_xz1914=== PAUSE TestIsValidCachePath/nar_xz1915=== RUN TestIsValidCachePath/nar_bz21916=== PAUSE TestIsValidCachePath/nar_bz21917=== RUN TestIsValidCachePath/nar_uncompressed1918=== PAUSE TestIsValidCachePath/nar_uncompressed19192026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.37ms)1920=== RUN TestIsValidCachePath/ls19212026/10/01 07:33:45 goose: successfully migrated database to version: 202609231200001922=== PAUSE TestIsValidCachePath/ls1923=== RUN TestIsValidCachePath/log1924=== PAUSE TestIsValidCachePath/log1925=== RUN TestIsValidCachePath/realisation1926=== PAUSE TestIsValidCachePath/realisation1927=== RUN TestIsValidCachePath/nix-cache-info1928=== PAUSE TestIsValidCachePath/nix-cache-info19292026-10-01 07:33:45.259 UTC [1232] ERROR: relation "goose_db_version" does not exist at character 3619302026-10-01 07:33:45.259 UTC [1232] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1931=== RUN TestIsValidCachePath/index.html1932=== PAUSE TestIsValidCachePath/index.html1933=== RUN TestIsValidCachePath/traversal_parent1934=== PAUSE TestIsValidCachePath/traversal_parent1935=== RUN TestIsValidCachePath/traversal_in_middle1936=== PAUSE TestIsValidCachePath/traversal_in_middle1937=== RUN TestIsValidCachePath/invalid_char_e1938=== PAUSE TestIsValidCachePath/invalid_char_e1939=== RUN TestIsValidCachePath/invalid_char_u1940=== PAUSE TestIsValidCachePath/invalid_char_u1941=== RUN TestIsValidCachePath/random_path1942=== PAUSE TestIsValidCachePath/random_path1943=== RUN TestIsValidCachePath/empty1944=== PAUSE TestIsValidCachePath/empty1945=== RUN TestIsValidCachePath/leading_slash1946=== PAUSE TestIsValidCachePath/leading_slash1947=== RUN TestIsValidCachePath/wrong_extension1948=== PAUSE TestIsValidCachePath/wrong_extension1949=== RUN TestIsValidCachePath/short_hash1950=== PAUSE TestIsValidCachePath/short_hash1951=== CONT TestReadProxyNarinfo19522026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.58ms)19532026/10/01 07:33:45 OK 2_object_stats_trigger.sql (2.13ms)19542026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.87ms)19552026/10/01 07:33:45 OK 3_commit_push.sql (1.31ms)19562026/10/01 07:33:45 goose: up to current file version: 319572026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.2ms)19582026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.43ms)19592026/10/01 07:33:45 OK 3_commit_push.sql (1.51ms)19602026/10/01 07:33:45 goose: up to current file version: 319612026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.42ms)19622026/10/01 07:33:45 OK 3_commit_push.sql (1.38ms)19632026/10/01 07:33:45 goose: up to current file version: 319642026-10-01 07:33:45.264 UTC [1234] ERROR: relation "goose_db_version" does not exist at character 3619652026-10-01 07:33:45.264 UTC [1234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19662026/10/01 07:33:45 OK 3_commit_push.sql (1.42ms)19672026/10/01 07:33:45 goose: up to current file version: 319682026/10/01 07:33:45 OK 20241026095416_initial_model.sql (13.17ms)19692026/10/01 07:33:45 OK 20241026095416_initial_model.sql (9.88ms)19702026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)19712026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)1972--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.38s)1973=== CONT TestProxyHeadersOnlyTrustedOnSocket19742026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.95ms)19752026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.96ms)19762026-10-01 07:33:45.288 UTC [1238] ERROR: relation "goose_db_version" does not exist at character 3619772026-10-01 07:33:45.288 UTC [1238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19782026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)19792026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)19802026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.44ms)19812026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.07ms)19822026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.62ms)19832026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.85ms)19842026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.35ms)19852026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000019862026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.23ms)19872026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000019882026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.33ms)19892026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures19902026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.67ms)19912026-10-01 07:33:45.301 UTC [1241] ERROR: relation "goose_db_version" does not exist at character 3619922026-10-01 07:33:45.301 UTC [1241] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19932026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.86ms)19942026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.83ms)19952026/10/01 07:33:45 OK 3_commit_push.sql (1.45ms)19962026/10/01 07:33:45 goose: up to current file version: 319972026/10/01 07:33:45 OK 3_commit_push.sql (1.15ms)19982026/10/01 07:33:45 goose: up to current file version: 319992026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.45ms)20002026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)20012026/10/01 07:33:45 OK 20251218171726_add_pins.sql (4.24ms)20022026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)20032026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.33ms)20042026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.93ms)20052026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)20062026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.56ms)20072026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes20082026-10-01 07:33:45.330 UTC [1242] ERROR: relation "goose_db_version" does not exist at character 3620092026-10-01 07:33:45.330 UTC [1242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20102026/10/01 07:33:45 OK 20251218171726_add_pins.sql (11.32ms)20112026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (9.99ms)20122026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000020132026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.87ms)20142026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)20152026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.72ms)20162026/10/01 07:33:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20172026/10/01 07:33:45 OK 3_commit_push.sql (2.13ms)20182026/10/01 07:33:45 goose: up to current file version: 320192026/10/01 07:33:45 INFO Signed narinfos id=1 count=12020--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.41s)2021=== CONT TestProxyWriteTimeout2022=== RUN TestProxyWriteTimeout/narinfo2023=== PAUSE TestProxyWriteTimeout/narinfo2024=== RUN TestProxyWriteTimeout/1_GiB_nar2025=== PAUSE TestProxyWriteTimeout/1_GiB_nar2026=== RUN TestProxyWriteTimeout/10_GiB_nar2027=== PAUSE TestProxyWriteTimeout/10_GiB_nar2028=== RUN TestProxyWriteTimeout/unknown_size2029=== PAUSE TestProxyWriteTimeout/unknown_size2030=== CONT TestParseSingleRange2031=== RUN TestParseSingleRange/none2032=== PAUSE TestParseSingleRange/none2033=== RUN TestParseSingleRange/unknown_unit2034=== PAUSE TestParseSingleRange/unknown_unit2035=== RUN TestParseSingleRange/multi-range_ignored2036=== PAUSE TestParseSingleRange/multi-range_ignored2037=== RUN TestParseSingleRange/malformed_no_dash2038=== PAUSE TestParseSingleRange/malformed_no_dash20392026-10-01 07:33:45.344 UTC [1243] ERROR: relation "goose_db_version" does not exist at character 3620402026-10-01 07:33:45.344 UTC [1243] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2041=== RUN TestParseSingleRange/malformed_both_empty2042=== PAUSE TestParseSingleRange/malformed_both_empty2043=== RUN TestParseSingleRange/malformed_end_before_start2044=== PAUSE TestParseSingleRange/malformed_end_before_start2045=== RUN TestParseSingleRange/closed2046=== PAUSE TestParseSingleRange/closed2047=== RUN TestParseSingleRange/open-ended2048=== PAUSE TestParseSingleRange/open-ended2049=== RUN TestParseSingleRange/end_clamped_to_size2050=== PAUSE TestParseSingleRange/end_clamped_to_size2051=== RUN TestParseSingleRange/suffix2052=== PAUSE TestParseSingleRange/suffix2053=== RUN TestParseSingleRange/suffix_exceeds_size2054=== PAUSE TestParseSingleRange/suffix_exceeds_size2055=== RUN TestParseSingleRange/single_byte2056=== PAUSE TestParseSingleRange/single_byte2057=== RUN TestParseSingleRange/start_past_EOF2058=== PAUSE TestParseSingleRange/start_past_EOF2059=== RUN TestParseSingleRange/start_far_past_EOF2060=== PAUSE TestParseSingleRange/start_far_past_EOF2061=== CONT TestGenerateLandingPage20622026/10/01 07:33:45 OK 20260905000000_add_claims.sql (7.33ms)2063--- PASS: TestGenerateLandingPage (0.00s)2064=== CONT TestService_NativeMTLS20652026/10/01 07:33:45 OK 20241026095416_initial_model.sql (15.2ms)20662026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (6.89ms)20672026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)20682026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.33ms)20692026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000020702026/10/01 07:33:45 OK 20251218171726_add_pins.sql (2.96ms)20712026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.07ms)20722026/10/01 07:33:45 OK 2_object_stats_trigger.sql (2.1ms)20732026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)20742026-10-01 07:33:45.364 UTC [1246] ERROR: relation "goose_db_version" does not exist at character 3620752026-10-01 07:33:45.364 UTC [1246] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20762026/10/01 07:33:45 OK 3_commit_push.sql (3.9ms)20772026/10/01 07:33:45 goose: up to current file version: 320782026/10/01 07:33:45 OK 20241026095416_initial_model.sql (16.37ms)2079--- PASS: TestReadProxyConditionalGet (0.41s)2080=== CONT TestCacheConfigHandlerMaxNarSize2081--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2082=== CONT TestService_ReadScope_PublicByDefault20832026/10/01 07:33:45 OK 20260905000000_add_claims.sql (10.34ms)20842026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (11.54ms)20852026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (10.79ms)20862026/10/01 07:33:45 OK 20241026095416_initial_model.sql (26.9ms)20872026/10/01 07:33:45 OK 20251218171726_add_pins.sql (20.89ms)20882026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (19.32ms)20892026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000020902026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (3.69ms)20912026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.6ms)20922026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)20932026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.96ms)20942026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.62ms)20952026/10/01 07:33:45 OK 3_commit_push.sql (1.34ms)20962026/10/01 07:33:45 goose: up to current file version: 320972026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.63ms)20982026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)20992026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.34ms)21002026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.18ms)21012026/10/01 07:33:45 INFO Received cleanup request method=DELETE path=/api/pending_closures21022026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.09ms)21032026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000021042026-10-01 07:33:45.418 UTC [1249] ERROR: relation "goose_db_version" does not exist at character 3621052026-10-01 07:33:45.418 UTC [1249] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21062026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.04ms)21072026/10/01 07:33:45 OK 1_commit_pending_closure.sql (3.05ms)21082026/10/01 07:33:45 INFO Aborted multipart uploads count=12109--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.40s)2110=== CONT TestClientErrorHandling2111=== RUN TestClientErrorHandling/InvalidStorePath2112=== PAUSE TestClientErrorHandling/InvalidStorePath2113=== RUN TestClientErrorHandling/InvalidAuthToken2114=== PAUSE TestClientErrorHandling/InvalidAuthToken2115=== RUN TestClientErrorHandling/ServerNotAvailable2116=== PAUSE TestClientErrorHandling/ServerNotAvailable2117=== CONT TestService_ReadAuthMiddleware21182026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.68ms)21192026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.37ms)21202026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000021212026/10/01 07:33:45 OK 3_commit_push.sql (1.29ms)21222026/10/01 07:33:45 goose: up to current file version: 321232026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.01ms)21242026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.27ms)2125--- PASS: TestMultipartCleanup (0.49s)2126=== CONT TestServerTLSConfig2127=== RUN TestServerTLSConfig/no_client_CA2128=== PAUSE TestServerTLSConfig/no_client_CA2129=== RUN TestServerTLSConfig/missing_CA_file2130=== PAUSE TestServerTLSConfig/missing_CA_file2131=== RUN TestServerTLSConfig/not_a_PEM_file2132=== PAUSE TestServerTLSConfig/not_a_PEM_file2133=== CONT TestClientCADerivations21342026/10/01 07:33:45 OK 3_commit_push.sql (847.71µs)21352026/10/01 07:33:45 goose: up to current file version: 321362026/10/01 07:33:45 OK 20241026095416_initial_model.sql (8.91ms)21372026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)2138=== RUN TestPush_RejectsBadRequests/no_roots2139=== PAUSE TestPush_RejectsBadRequests/no_roots2140=== RUN TestPush_RejectsBadRequests/no_objects2141=== PAUSE TestPush_RejectsBadRequests/no_objects2142=== RUN TestPush_RejectsBadRequests/bad_root2143=== PAUSE TestPush_RejectsBadRequests/bad_root2144=== RUN TestPush_RejectsBadRequests/root_not_in_objects2145=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2146=== CONT TestService_RequireScope_OIDC21472026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.96ms)21482026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)21492026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.66ms)21502026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.55ms)21512026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.33ms)21522026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000021532026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.5ms)21542026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.37ms)21552026/10/01 07:33:45 OK 3_commit_push.sql (1.17ms)21562026/10/01 07:33:45 goose: up to current file version: 32157--- PASS: TestReadProxyHead (0.42s)2158=== CONT TestCreatePendingClosureRejectsOversizedNAR21592026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures2160--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2161=== CONT TestCacheConfigHandler2162=== RUN TestCacheConfigHandler/full_config,_no_issuer2163=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2164=== RUN TestCacheConfigHandler/no_cache_url_configured2165=== PAUSE TestCacheConfigHandler/no_cache_url_configured2166=== RUN TestCacheConfigHandler/no_signing_keys2167=== PAUSE TestCacheConfigHandler/no_signing_keys2168=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2169=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2170=== CONT TestCacheStatsHandler21712026-10-01 07:33:45.473 UTC [1255] ERROR: relation "goose_db_version" does not exist at character 3621722026-10-01 07:33:45.473 UTC [1255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21732026/10/01 07:33:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40203/oidc21742026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes21752026/10/01 07:33:45 OK 20241026095416_initial_model.sql (14.8ms)21762026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)21772026-10-01 07:33:45.497 UTC [1259] ERROR: relation "goose_db_version" does not exist at character 3621782026-10-01 07:33:45.497 UTC [1259] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21792026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.66ms)21802026/10/01 07:33:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21812026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)2182--- PASS: TestReadProxyInvalidPath (0.38s)2183=== CONT TestMetricsInventory21842026/10/01 07:33:45 INFO Received complete push request method=POST path=/api/pushes/1/complete21852026-10-01 07:33:45.506 UTC [1261] ERROR: relation "goose_db_version" does not exist at character 3621862026-10-01 07:33:45.506 UTC [1261] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21872026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4ms)21882026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.8ms)21892026/10/01 07:33:45 OK 20241026095416_initial_model.sql (9.59ms)21902026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)21912026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.95ms)21922026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000021932026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes21942026/10/01 07:33:45 OK 1_commit_pending_closure.sql (3.07ms)21952026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.42ms)21962026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.39ms)21972026/10/01 07:33:45 OK 3_commit_push.sql (773.03µs)21982026/10/01 07:33:45 goose: up to current file version: 321992026/10/01 07:33:45 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTY1Mzc0OGUtZjdiNi00NmM4LWI2NTAtZDUwYzU1YzI1ZmZmLmU0NDYyOTI2LTk4MjYtNGI3Ny04OTM0LTUzNWExMDg2NWI3N3gxNzkwODQwMDI1MDk5NTEwNjgw parts=1222002026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)22012026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.11ms)22022026/10/01 07:33:45 INFO Received uploads request method=POST path=/api/pending_closures22032026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)22042026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.46ms)2205--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.86s)2206=== CONT TestService_AuthMiddleware_OIDC22072026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.21ms)22082026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes22092026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.02ms)22102026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.46ms)22112026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000022122026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)22132026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.95ms)22142026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.5ms)22152026/10/01 07:33:45 OK 3_commit_push.sql (1.43ms)22162026/10/01 07:33:45 goose: up to current file version: 322172026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.91ms)22182026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.65ms)22192026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.84ms)22202026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000022212026-10-01 07:33:45.543 UTC [1264] ERROR: relation "goose_db_version" does not exist at character 3622222026-10-01 07:33:45.543 UTC [1264] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22232026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.27ms)22242026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.34ms)22252026/10/01 07:33:45 OK 3_commit_push.sql (1.34ms)22262026/10/01 07:33:45 goose: up to current file version: 322272026/10/01 07:33:45 INFO Received complete push request method=POST path=/api/pushes/1/complete2228--- PASS: TestPush_CompleteCommitsEveryRoot (0.43s)2229=== CONT TestNARDeduplicationMetadataUploadBug22302026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.03ms)22312026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)22322026-10-01 07:33:45.564 UTC [1267] ERROR: relation "goose_db_version" does not exist at character 3622332026-10-01 07:33:45.564 UTC [1267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22342026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.88ms)22352026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)22362026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.05ms)22372026/10/01 07:33:45 INFO Aborted multipart uploads count=02238--- PASS: TestReadProxy404 (0.44s)2239=== CONT TestService_readinessHandler22402026/10/01 07:33:45 WARN Force mode enabled - objects will be deleted immediately without grace period22412026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.25ms)22422026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.35ms)22432026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.74ms)22442026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000022452026-10-01 07:33:45.582 UTC [1270] ERROR: relation "goose_db_version" does not exist at character 3622462026-10-01 07:33:45.582 UTC [1270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22472026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)22482026/10/01 07:33:45 OK 1_commit_pending_closure.sql (1.85ms)22492026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.95ms)22502026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.51ms)22512026/10/01 07:33:45 OK 3_commit_push.sql (1.6ms)22522026/10/01 07:33:45 goose: up to current file version: 322532026/10/01 07:33:45 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=022542026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (9.12ms)22552026/10/01 07:33:45 INFO Vacuumed table table=pending_closures22562026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.86ms)22572026/10/01 07:33:45 INFO Vacuumed table table=pending_objects22582026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.09ms)22592026/10/01 07:33:45 INFO Vacuumed table table=multipart_uploads22602026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)22612026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.96ms)22622026/10/01 07:33:45 INFO Vacuumed table table=closures22632026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.92ms)22642026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.34ms)22652026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000022662026/10/01 07:33:45 INFO Vacuumed table table=objects22672026/10/01 07:33:45 INFO Received complete push request method=POST path=/api/pushes/2/complete22682026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.58ms)22692026/10/01 07:33:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22702026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)22712026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.94ms)2272--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.54s)2273=== CONT TestService_AuthMiddleware_MTLSBoundSubjects22742026/10/01 07:33:45 OK 3_commit_push.sql (2.36ms)22752026/10/01 07:33:45 goose: up to current file version: 322762026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.98ms)22772026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.07ms)22782026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.02ms)22792026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000022802026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes22812026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.11ms)22822026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.25ms)22832026/10/01 07:33:45 OK 3_commit_push.sql (1.21ms)22842026/10/01 07:33:45 goose: up to current file version: 322852026/10/01 07:33:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTY1Mzc0OGUtZjdiNi00NmM4LWI2NTAtZDUwYzU1YzI1ZmZmLjFhOTU2YThjLTcxMDUtNDg0Mi1iM2NlLWJkMjU3MGFhNzhiYngxNzkwODQwMDI1MTk2MjUyNjMz parts=122286--- PASS: TestRedundantMultipartUpload (0.80s)2287=== CONT TestService_healthCheckHandler22882026-10-01 07:33:45.629 UTC [1275] ERROR: relation "goose_db_version" does not exist at character 3622892026-10-01 07:33:45.629 UTC [1275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2290--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.47s)2291=== CONT TestService_AuthMiddleware_MTLSProxyHeader22922026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.98ms)22932026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)22942026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.68ms)22952026-10-01 07:33:45.655 UTC [1282] ERROR: relation "goose_db_version" does not exist at character 3622962026-10-01 07:33:45.655 UTC [1282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2297--- PASS: TestObjectStatsTrigger (0.48s)2298=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22992026/10/01 07:33:45 INFO Received uploads request method=POST path=/2300=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23012026/10/01 07:33:45 INFO Received request for more parts method=POST path=/2302=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23032026/10/01 07:33:45 INFO Received uploads request method=POST path=/2304=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23052026/10/01 07:33:45 INFO Received complete multipart upload request method=POST path=/23062026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)2307--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2308 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2309 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2310 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2311 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2312=== CONT TestResolveDBConnectionString/flag_wins2313=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2314=== CONT TestResolveDBConnectionString/nothing_configured2315=== CONT TestResolveDBConnectionString/missing_file_is_an_error2316=== CONT TestResolveDBConnectionString/file_when_flag_empty2317=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23182026/10/01 07:33:45 INFO Received uploads request method=POST path=/2319--- PASS: TestResolveDBConnectionString (0.00s)2320 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2321 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2322 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2323 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2324 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)23252026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.53ms)23262026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.33ms)23272026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.06ms)23282026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000023292026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.27ms)23302026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.39ms)23312026/10/01 07:33:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux23322026/10/01 07:33:45 OK 3_commit_push.sql (1.3ms)23332026/10/01 07:33:45 goose: up to current file version: 323342026/10/01 07:33:45 WARN Refused reserved pin name=worker-x86_64-linux23352026/10/01 07:33:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux23362026/10/01 07:33:45 INFO Received create pin request method=POST path=/api/pins/my-app23372026/10/01 07:33:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2338--- PASS: TestCreatePin_ReservedPins (0.61s)2339=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23402026/10/01 07:33:45 INFO Received request for more parts method=POST path=/23412026/10/01 07:33:45 OK 20241026095416_initial_model.sql (12.36ms)23422026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)23432026/10/01 07:33:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41055/oidc23442026/10/01 07:33:45 OK 20251218171726_add_pins.sql (9.98ms)23452026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)23462026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.92ms)23472026-10-01 07:33:45.695 UTC [1285] ERROR: relation "goose_db_version" does not exist at character 3623482026-10-01 07:33:45.695 UTC [1285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2349--- PASS: TestReadRedirectUsesPublicS3URL (0.48s)2350=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23512026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.42ms)23522026/10/01 07:33:45 INFO Received complete multipart upload request method=POST path=/23532026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.69ms)23542026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000023552026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.47ms)23562026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.86ms)23572026-10-01 07:33:45.706 UTC [1286] ERROR: relation "goose_db_version" does not exist at character 3623582026-10-01 07:33:45.706 UTC [1286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23592026/10/01 07:33:45 OK 3_commit_push.sql (1.87ms)23602026/10/01 07:33:45 goose: up to current file version: 32361--- PASS: TestReadProxyRangeRequest (0.46s)2362=== CONT TestIsValidUploadKey/narinfo2363=== CONT TestIsValidUploadKey/realisation_plus_in_output2364=== CONT TestIsValidUploadKey/unknown_type2365=== CONT TestIsValidUploadKey/empty_key2366=== CONT TestIsValidUploadKey/absolute2367=== CONT TestIsValidUploadKey/traversal_nar2368=== CONT TestIsValidUploadKey/traversal2369=== CONT TestIsValidUploadKey/index.html2370=== CONT TestIsValidUploadKey/nix-cache-info2371=== CONT TestIsValidUploadKey/build_log_home-manager_file2372=== CONT TestIsValidUploadKey/realisation2373=== CONT TestIsValidUploadKey/build_log_equals2374=== CONT TestIsValidUploadKey/build_log_question_mark2375=== CONT TestIsValidUploadKey/build_log_plus_in_name2376=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2377=== CONT TestIsValidUploadKey/nar_plain2378=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2379=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2380=== CONT TestIsValidUploadKey/build_log2381=== CONT TestIsValidUploadKey/listing2382=== CONT TestIsValidUploadKey/nar_xz2383=== CONT TestIsValidUploadKey/nar_zst2384=== CONT TestIsValidCachePath/narinfo2385=== CONT TestIsValidCachePath/wrong_extension2386=== CONT TestIsValidCachePath/short_hash2387--- PASS: TestIsValidUploadKey (0.00s)2388 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2389 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2390 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2391 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2392 --- PASS: TestIsValidUploadKey/absolute (0.00s)2393 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2394 --- PASS: TestIsValidUploadKey/traversal (0.00s)2395 --- PASS: TestIsValidUploadKey/index.html (0.00s)2396 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2397 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2398 --- PASS: TestIsValidUploadKey/realisation (0.00s)2399 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2400 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2401 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2402 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2403 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2404 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2405 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2406 --- PASS: TestIsValidUploadKey/build_log (0.00s)2407 --- PASS: TestIsValidUploadKey/listing (0.00s)2408 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2409 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2410=== CONT TestIsValidCachePath/leading_slash2411=== CONT TestIsValidCachePath/realisation2412=== CONT TestIsValidCachePath/log2413=== CONT TestIsValidCachePath/ls2414=== CONT TestIsValidCachePath/nar_uncompressed2415=== CONT TestIsValidCachePath/nar_bz22416=== CONT TestIsValidCachePath/nix-cache-info2417=== CONT TestIsValidCachePath/nar_xz2418=== CONT TestIsValidCachePath/nar_zst2419=== CONT TestIsValidCachePath/empty2420=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2421=== CONT TestIsValidCachePath/random_path2422=== CONT TestIsValidCachePath/invalid_char_u2423=== CONT TestIsValidCachePath/traversal_in_middle2424=== CONT TestIsValidCachePath/traversal_parent2425=== CONT TestIsValidCachePath/invalid_char_e2426=== CONT TestIsValidCachePath/index.html2427--- PASS: TestIsValidCachePath (0.00s)2428 --- PASS: TestIsValidCachePath/narinfo (0.00s)2429 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2430 --- PASS: TestIsValidCachePath/short_hash (0.00s)2431 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2432 --- PASS: TestIsValidCachePath/realisation (0.00s)2433 --- PASS: TestIsValidCachePath/log (0.00s)2434 --- PASS: TestIsValidCachePath/ls (0.00s)2435 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2436 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2437 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2438 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2439 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2440 --- PASS: TestIsValidCachePath/empty (0.00s)2441 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2442 --- PASS: TestIsValidCachePath/random_path (0.00s)2443 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2444 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2445 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2446 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2447 --- PASS: TestIsValidCachePath/index.html (0.00s)2448=== CONT TestProxyWriteTimeout/narinfo2449=== CONT TestProxyWriteTimeout/unknown_size2450=== CONT TestProxyWriteTimeout/10_GiB_nar2451=== CONT TestProxyWriteTimeout/1_GiB_nar2452--- PASS: TestProxyWriteTimeout (0.00s)2453 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2454 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2455 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2456 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2457=== CONT TestParseSingleRange/none2458=== CONT TestParseSingleRange/open-ended2459=== CONT TestParseSingleRange/suffix_exceeds_size2460=== CONT TestParseSingleRange/suffix2461=== CONT TestParseSingleRange/single_byte24622026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.05ms)2463=== CONT TestParseSingleRange/end_clamped_to_size2464=== CONT TestParseSingleRange/start_far_past_EOF2465=== CONT TestParseSingleRange/start_past_EOF2466=== CONT TestParseSingleRange/malformed_both_empty2467=== CONT TestParseSingleRange/multi-range_ignored2468=== CONT TestParseSingleRange/malformed_end_before_start2469=== CONT TestParseSingleRange/malformed_no_dash2470=== CONT TestParseSingleRange/unknown_unit2471=== CONT TestParseSingleRange/closed2472--- PASS: TestParseSingleRange (0.00s)2473 --- PASS: TestParseSingleRange/none (0.00s)2474 --- PASS: TestParseSingleRange/open-ended (0.00s)2475 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2476 --- PASS: TestParseSingleRange/suffix (0.00s)2477 --- PASS: TestParseSingleRange/single_byte (0.00s)2478 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2479 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2480 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2481 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2482 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2483 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2484 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2485 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2486 --- PASS: TestParseSingleRange/closed (0.00s)2487=== CONT TestClientErrorHandling/InvalidStorePath24882026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)24892026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.57ms)24902026-10-01 07:33:45.720 UTC [1288] ERROR: relation "goose_db_version" does not exist at character 3624912026-10-01 07:33:45.720 UTC [1288] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24922026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.08ms)24932026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)24942026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (2ms)24952026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.42ms)24962026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.73ms)2497--- PASS: TestReadProxyNarinfo (0.47s)2498=== CONT TestClientErrorHandling/InvalidAuthToken24992026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (3.38ms)2500=== CONT TestClientErrorHandling/ServerNotAvailable25012026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)25022026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (3.21ms)25032026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000025042026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.77ms)25052026/10/01 07:33:45 OK 20260905000000_add_claims.sql (4.48ms)25062026/10/01 07:33:45 OK 20241026095416_initial_model.sql (11.79ms)25072026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.48ms)25082026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)25092026/10/01 07:33:45 OK 3_commit_push.sql (1.23ms)25102026/10/01 07:33:45 goose: up to current file version: 325112026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.73ms)25122026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.13ms)25132026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000025142026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.82ms)25152026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.01ms)25162026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.39ms)25172026/10/01 07:33:45 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket474919313/001/proxy.sock25182026/10/01 07:33:45 INFO Starting HTTP server address=127.0.0.1:3543725192026/10/01 07:33:45 WARN mTLS auth: subject not in bound subjects subject="CN=someone"25202026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)25212026/10/01 07:33:45 INFO Shutdown signal received, draining in-flight requests timeout=10s25222026/10/01 07:33:45 OK 3_commit_push.sql (1.66ms)2523--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.46s)25242026/10/01 07:33:45 goose: up to current file version: 32525=== CONT TestServerTLSConfig/no_client_CA2526=== CONT TestServerTLSConfig/not_a_PEM_file2527=== CONT TestServerTLSConfig/missing_CA_file2528--- PASS: TestServerTLSConfig (0.00s)2529 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2530 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2531 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2532=== CONT TestPush_RejectsBadRequests/no_roots25332026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes2534=== CONT TestPush_RejectsBadRequests/bad_root25352026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes2536=== CONT TestPush_RejectsBadRequests/no_objects25372026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes2538=== CONT TestPush_RejectsBadRequests/root_not_in_objects25392026/10/01 07:33:45 INFO Received push request method=POST path=/api/pushes2540=== CONT TestCacheConfigHandler/full_config,_no_issuer2541--- PASS: TestPush_RejectsBadRequests (0.40s)2542 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2543 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2544 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2545 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2546=== CONT TestCacheConfigHandler/no_signing_keys2547=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2548=== CONT TestCacheConfigHandler/no_cache_url_configured2549--- PASS: TestCacheConfigHandler (0.00s)2550 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2551 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2552 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2553 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)25542026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.45ms)25552026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.81ms)25562026-10-01 07:33:45.753 UTC [1293] ERROR: relation "goose_db_version" does not exist at character 3625572026-10-01 07:33:45.753 UTC [1293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25582026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (2.7ms)25592026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000025602026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.63ms)25612026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.36ms)25622026/10/01 07:33:45 OK 3_commit_push.sql (1.02ms)25632026/10/01 07:33:45 goose: up to current file version: 325642026/10/01 07:33:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"25652026/10/01 07:33:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2566--- PASS: TestService_NativeMTLS (0.42s)25672026/10/01 07:33:45 OK 20241026095416_initial_model.sql (9.6ms)25682026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)25692026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.2ms)25702026-10-01 07:33:45.783 UTC [1311] ERROR: relation "goose_db_version" does not exist at character 3625712026-10-01 07:33:45.783 UTC [1311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25722026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (10.03ms)2573--- PASS: TestService_ReadScope_PublicByDefault (0.42s)25742026/10/01 07:33:45 OK 20260905000000_add_claims.sql (7.02ms)25752026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.25ms)25762026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (1.58ms)25772026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000025782026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2.09ms)25792026/10/01 07:33:45 OK 2_object_stats_trigger.sql (1.1ms)25802026/10/01 07:33:45 OK 3_commit_push.sql (692.97µs)25812026/10/01 07:33:45 goose: up to current file version: 325822026/10/01 07:33:45 OK 20241026095416_initial_model.sql (9.43ms)25832026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)25842026-10-01 07:33:45.805 UTC [1313] ERROR: relation "goose_db_version" does not exist at character 3625852026-10-01 07:33:45.805 UTC [1313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25862026/10/01 07:33:45 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/present25872026/10/01 07:33:45 OK 20251218171726_add_pins.sql (2.88ms)2588--- PASS: TestService_ReadAuthMiddleware (0.39s)25892026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)25902026/10/01 07:33:45 OK 20260905000000_add_claims.sql (2.92ms)25912026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.16ms)25922026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (1.65ms)25932026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000025942026/10/01 07:33:45 OK 1_commit_pending_closure.sql (2ms)25952026/10/01 07:33:45 OK 2_object_stats_trigger.sql (929.09µs)25962026/10/01 07:33:45 OK 3_commit_push.sql (620.75µs)25972026/10/01 07:33:45 goose: up to current file version: 325982026/10/01 07:33:45 OK 20241026095416_initial_model.sql (10.39ms)25992026/10/01 07:33:45 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)26002026/10/01 07:33:45 OK 20251218171726_add_pins.sql (3.95ms)26012026/10/01 07:33:45 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)26022026/10/01 07:33:45 OK 20260905000000_add_claims.sql (3.46ms)26032026/10/01 07:33:45 OK 20260920000000_drop_claims.sql (2.08ms)26042026/10/01 07:33:45 OK 20260923120000_add_pushes.sql (1.79ms)26052026/10/01 07:33:45 goose: successfully migrated database to version: 2026092312000026062026/10/01 07:33:45 OK 1_commit_pending_closure.sql (1.98ms)26072026/10/01 07:33:45 OK 2_object_stats_trigger.sql (990.93µs)26082026/10/01 07:33:45 OK 3_commit_push.sql (901.55µs)26092026/10/01 07:33:45 goose: up to current file version: 32610--- PASS: TestCacheStatsHandler (0.39s)2611=== RUN TestService_RequireScope_OIDC/builder_may_write2612=== PAUSE TestService_RequireScope_OIDC/builder_may_write2613=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2614=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2615=== RUN TestService_RequireScope_OIDC/ops_may_admin2616=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2617=== RUN TestService_RequireScope_OIDC/ops_may_not_write2618=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2619=== RUN TestService_RequireScope_OIDC/reader_may_not_write2620=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2621=== RUN TestService_RequireScope_OIDC/static_token_may_admin2622=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2623=== RUN TestService_RequireScope_OIDC/static_token_may_write2624=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2625=== RUN TestService_RequireScope_OIDC/reader_may_read2626=== PAUSE TestService_RequireScope_OIDC/reader_may_read2627=== RUN TestService_RequireScope_OIDC/writer_implies_read2628=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2629=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2630=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2631=== CONT TestService_RequireScope_OIDC/builder_may_write2632=== CONT TestService_RequireScope_OIDC/static_token_may_admin2633=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2634=== CONT TestService_RequireScope_OIDC/reader_may_not_write2635=== CONT TestService_RequireScope_OIDC/reader_may_read2636=== CONT TestService_RequireScope_OIDC/static_token_may_write2637=== CONT TestService_RequireScope_OIDC/ops_may_not_write2638=== CONT TestService_RequireScope_OIDC/ops_may_admin2639=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2640=== CONT TestService_RequireScope_OIDC/writer_implies_read2641--- PASS: TestService_RequireScope_OIDC (0.45s)2642 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2643 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2644 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2645 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2646 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2647 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2648 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2649 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2650 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2651 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2652=== NAME TestOrphanedObjectsGC2653 orphaned_objects_gc_test.go:290: GC Test Summary:2654 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2655 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2656 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2657 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2658 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2659--- PASS: TestOrphanedObjectsGC (0.76s)2660--- PASS: TestMetricsInventory (0.39s)26612026/10/01 07:33:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.852605ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2662=== NAME TestClientCADerivations2663 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2715904133/001/store/jhf7v1d1i4bhh49471d6bawrpskzqzwm-ca-test26642026/10/01 07:33:45 WARN readiness check failed error="closed pool"2665--- PASS: TestService_readinessHandler (0.35s)26662026/10/01 07:33:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26672026/10/01 07:33:45 WARN mTLS auth: bound subjects configured but subject DN unavailable26682026/10/01 07:33:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2669--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.33s)2670=== NAME TestNARDeduplicationMetadataUploadBug2671 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2681441322/001/store/3zjj3habh4p09yiql4vg91577rbxrvdg-file1.txt2672=== NAME TestClientCADerivations2673 client_ca_test.go:139: Found 1 dependencies (including self)2674--- PASS: TestService_healthCheckHandler (0.33s)2675--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)2676=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2677=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2678=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2679=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2680=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2681=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2682=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2683=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2684=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2685=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2686=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26872026/10/01 07:33:45 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]2688=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured26892026/10/01 07:33:45 WARN Authentication failed token_preview=eyJhbGciOi...VHOY3xVMCw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2690--- PASS: TestService_AuthMiddleware_OIDC (0.47s)2691 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2692 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2693 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2694 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)26952026/10/01 07:33:46 INFO Received push request method=POST path=/api/pushes26962026/10/01 07:33:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26972026/10/01 07:33:46 INFO Uploading 3zjj3habh4p09yiql4vg91577rbxrvdg-file1.txt (160B)26982026/10/01 07:33:46 WARN Failed to register uploaded object key=3zjj3habh4p09yiql4vg91577rbxrvdg.ls error="server returned 404: 404 page not found\n"26992026/10/01 07:33:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27002026/10/01 07:33:46 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"27012026/10/01 07:33:46 INFO Signed narinfos id=1 count=127022026/10/01 07:33:46 INFO Uploading 1 narinfos27032026/10/01 07:33:46 INFO Received complete push request method=POST path=/api/pushes/1/complete27042026/10/01 07:33:46 WARN Failed to register uploaded object key=3zjj3habh4p09yiql4vg91577rbxrvdg.narinfo error="server returned 404: 404 page not found\n"27052026/10/01 07:33:46 INFO Upload complete. (58ms)2706=== NAME TestNARDeduplicationMetadataUploadBug2707 metadata_upload_test.go:54: Retrieved narinfo from S3:2708 StorePath: /build/TestNARDeduplicationMetadataUploadBug2681441322/001/store/3zjj3habh4p09yiql4vg91577rbxrvdg-file1.txt2709 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2710 Compression: zstd2711 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2712 NarSize: 1602713 References: 2714 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2715 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2716 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2717 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}27182026/10/01 07:33:46 INFO Received push request method=POST path=/api/pushes27192026/10/01 07:33:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27202026/10/01 07:33:46 INFO Uploading jhf7v1d1i4bhh49471d6bawrpskzqzwm-ca-test (144B)27212026/10/01 07:33:46 WARN Failed to register uploaded object key=log/sfq1ss2ivrgk2g1161dxm717wxnvbsf9-ca-test.drv error="server returned 404: 404 page not found\n"27222026/10/01 07:33:46 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"27232026/10/01 07:33:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27242026/10/01 07:33:46 WARN Failed to register uploaded object key=jhf7v1d1i4bhh49471d6bawrpskzqzwm.ls error="server returned 404: 404 page not found\n"27252026/10/01 07:33:46 INFO Signed narinfos id=1 count=127262026/10/01 07:33:46 INFO Uploading 1 narinfos27272026/10/01 07:33:46 INFO Received complete push request method=POST path=/api/pushes/1/complete27282026/10/01 07:33:46 WARN Failed to register uploaded object key=jhf7v1d1i4bhh49471d6bawrpskzqzwm.narinfo error="server returned 404: 404 page not found\n"27292026/10/01 07:33:46 INFO Upload complete. (85ms)2730=== NAME TestClientCADerivations2731 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2715904133/001/store/jhf7v1d1i4bhh49471d6bawrpskzqzwm-ca-test2732 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2733 Compression: zstd2734 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2735 NarSize: 1442736 References: 2737 Deriver: /build/TestClientCADerivations2715904133/001/store/sfq1ss2ivrgk2g1161dxm717wxnvbsf9-ca-test.drv2738 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2739 client_ca_test.go:185: Checking for realisation files in S3...2740 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2741 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2742=== NAME TestNARDeduplicationMetadataUploadBug2743 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2681441322/001/store/l500snicigiqd60mg5cbw8h0y7xwxw1z-file2.txt27442026/10/01 07:33:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.077721ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2745=== NAME TestClientCADerivations2746 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2747 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2748 error: binary cache 's3://bucket63?endpoint=http://localhost:44605®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2715904133/001/store'2749 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12750--- PASS: TestClientCADerivations (0.73s)27512026/10/01 07:33:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27522026/10/01 07:33:46 INFO Received push request method=POST path=/api/pushes27532026/10/01 07:33:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27542026/10/01 07:33:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)27552026/10/01 07:33:46 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign27562026/10/01 07:33:46 INFO Signed narinfos id=2 count=127572026/10/01 07:33:46 WARN Failed to register uploaded object key=l500snicigiqd60mg5cbw8h0y7xwxw1z.ls error="server returned 404: 404 page not found\n"27582026/10/01 07:33:46 INFO Uploading 1 narinfos27592026/10/01 07:33:46 INFO Received complete push request method=POST path=/api/pushes/2/complete27602026/10/01 07:33:46 WARN Failed to register uploaded object key=l500snicigiqd60mg5cbw8h0y7xwxw1z.narinfo error="server returned 404: 404 page not found\n"27612026/10/01 07:33:46 INFO Upload complete. (48ms)2762=== NAME TestNARDeduplicationMetadataUploadBug2763 metadata_upload_test.go:76: Retrieved narinfo from S3:2764 StorePath: /build/TestNARDeduplicationMetadataUploadBug2681441322/001/store/l500snicigiqd60mg5cbw8h0y7xwxw1z-file2.txt2765 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2766 Compression: zstd2767 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2768 NarSize: 1602769 References: 2770 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2771 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2772 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2773 {"version":1,"root":{"type":"regular","size":44}}2774--- PASS: TestNARDeduplicationMetadataUploadBug (0.79s)27752026/10/01 07:33:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=765.441447ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2776--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2777 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2778 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2779 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.90s)2780=== NAME TestOrphanedObjectsGCStressTest2781 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2782 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion27832026/10/01 07:33:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02784=== NAME TestClientIntegration2785 client_integration_test.go:323: Objects in database after GC:2786 client_integration_test.go:323: Successfully deleted all objects with GC --force2787--- PASS: TestClientIntegration (2.88s)27882026/10/01 07:33:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02789=== NAME TestPinProtectsFromGC2790 client_integration_test.go:794: Pin successfully protected closure from garbage collection2791--- PASS: TestPinProtectsFromGC (2.93s)27922026/10/01 07:33:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.51099939s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2793=== NAME TestOrphanedObjectsGCStressTest2794 orphaned_objects_gc_test.go:509: Stress test completed successfully:2795 orphaned_objects_gc_test.go:510: - Active objects preserved: 202796 orphaned_objects_gc_test.go:511: - Objects deleted: 2102797 orphaned_objects_gc_test.go:512: - Total GC'd: 2102798--- PASS: TestOrphanedObjectsGCStressTest (2.13s)27992026/10/01 07:33:48 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-config28002026/10/01 07:33:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.732369ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28012026/10/01 07:33:49 WARN Rate limiter enabled after throttle name=s3-test rate=528022026/10/01 07:33:49 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2803=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2804 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102805 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002806--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.89s)28072026/10/01 07:33:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.662939ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28082026/10/01 07:33:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=796.372599ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28092026/10/01 07:33:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.537847659s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28102026/10/01 07:33:51 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"28112026/10/01 07:33:51 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-config28122026/10/01 07:33:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.276157ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28132026/10/01 07:33:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.101408ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28142026/10/01 07:33:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=869.35239ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28152026/10/01 07:33:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.479442995s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config28162026/10/01 07:33:54 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_closures28172026/10/01 07:33:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.644091ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28182026/10/01 07:33:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=403.681817ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28192026/10/01 07:33:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=753.176755ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures28202026/10/01 07:33:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.508869555s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2821--- PASS: TestClientErrorHandling (0.00s)2822 --- PASS: TestClientErrorHandling/InvalidStorePath (0.33s)2823 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.60s)2824 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.11s)2825PASS28262026-10-01 07:33:58.048 UTC [128] LOG: received smart shutdown request28272026-10-01 07:33:58.051 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 128282026-10-01 07:33:58.063 UTC [133] LOG: shutting down28292026-10-01 07:33:58.063 UTC [133] LOG: checkpoint starting: shutdown immediate28302026-10-01 07:33:58.846 UTC [133] LOG: checkpoint complete: wrote 10826 buffers (66.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 21 recycled; write=0.190 s, sync=0.572 s, total=0.784 s; sync files=24927, longest=0.041 s, average=0.001 s; distance=339156 kB, estimate=339156 kB; lsn=0/1629AF20, redo lsn=0/1629AF2028312026-10-01 07:33:58.919 UTC [128] LOG: database system is shut down2832Running OIDC tests...2833=== RUN TestAudienceForIssuer2834=== PAUSE TestAudienceForIssuer2835=== RUN TestGlobMatch2836=== PAUSE TestGlobMatch2837=== RUN TestValidateToken_ValidToken2838=== PAUSE TestValidateToken_ValidToken2839=== RUN TestValidateToken_WrongAudience2840=== PAUSE TestValidateToken_WrongAudience2841=== RUN TestValidateToken_Expired2842=== PAUSE TestValidateToken_Expired2843=== RUN TestValidateToken_BoundClaimsMismatch2844=== PAUSE TestValidateToken_BoundClaimsMismatch2845=== RUN TestValidateToken_BoundSubjectMismatch2846=== PAUSE TestValidateToken_BoundSubjectMismatch2847=== RUN TestValidateToken_MultipleProviders2848=== PAUSE TestValidateToken_MultipleProviders2849=== RUN TestValidateToken_NoMatchingProvider2850=== PAUSE TestValidateToken_NoMatchingProvider2851=== RUN TestValidateToken_KubernetesServiceAccount2852=== PAUSE TestValidateToken_KubernetesServiceAccount2853=== RUN TestNewValidator_KubernetesRequiresCA2854=== PAUSE TestNewValidator_KubernetesRequiresCA2855=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2856=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2857=== RUN TestPins_ReservedForMatchingRule2858=== PAUSE TestPins_ReservedForMatchingRule2859=== RUN TestPins_TopLevelShorthand2860=== PAUSE TestPins_TopLevelShorthand2861=== RUN TestPins_ConfigValidation2862=== PAUSE TestPins_ConfigValidation2863=== RUN TestScopes_LegacyProviderDefaultsToWrite2864=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2865=== RUN TestScopes_Rules2866=== PAUSE TestScopes_Rules2867=== RUN TestScopes_ConfigValidation2868=== PAUSE TestScopes_ConfigValidation2869=== CONT TestAudienceForIssuer2870=== CONT TestValidateToken_KubernetesServiceAccount2871--- PASS: TestAudienceForIssuer (0.00s)2872=== CONT TestValidateToken_Expired2873=== CONT TestPins_ConfigValidation2874=== CONT TestValidateToken_BoundClaimsMismatch2875=== CONT TestScopes_Rules2876=== CONT TestValidateToken_MultipleProviders2877=== CONT TestPins_ReservedForMatchingRule2878=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2879=== CONT TestNewValidator_KubernetesRequiresCA2880=== CONT TestValidateToken_ValidToken2881=== CONT TestValidateToken_BoundSubjectMismatch2882=== CONT TestGlobMatch2883=== RUN TestGlobMatch/foo_foo2884=== PAUSE TestGlobMatch/foo_foo2885=== RUN TestGlobMatch/foo_bar2886=== PAUSE TestGlobMatch/foo_bar2887=== CONT TestScopes_LegacyProviderDefaultsToWrite2888--- PASS: TestPins_ConfigValidation (0.00s)2889=== RUN TestGlobMatch/*_2890=== PAUSE TestGlobMatch/*_2891=== CONT TestScopes_ConfigValidation2892=== CONT TestPins_TopLevelShorthand2893=== CONT TestValidateToken_WrongAudience2894=== CONT TestValidateToken_NoMatchingProvider2895=== RUN TestGlobMatch/*_anything2896=== PAUSE TestGlobMatch/*_anything2897=== RUN TestGlobMatch/foo*_foo2898=== PAUSE TestGlobMatch/foo*_foo2899=== RUN TestGlobMatch/foo*_foobar2900=== PAUSE TestGlobMatch/foo*_foobar2901=== RUN TestGlobMatch/foo*_bar2902--- PASS: TestScopes_ConfigValidation (0.00s)2903=== PAUSE TestGlobMatch/foo*_bar2904=== RUN TestGlobMatch/*bar_bar2905=== PAUSE TestGlobMatch/*bar_bar2906=== RUN TestGlobMatch/*bar_foobar2907=== PAUSE TestGlobMatch/*bar_foobar2908=== RUN TestGlobMatch/*bar_foo2909=== PAUSE TestGlobMatch/*bar_foo2910=== RUN TestGlobMatch/foo*bar_foobar2911=== PAUSE TestGlobMatch/foo*bar_foobar2912=== RUN TestGlobMatch/foo*bar_foo123bar2913=== PAUSE TestGlobMatch/foo*bar_foo123bar2914=== RUN TestGlobMatch/foo*bar_foobarbaz2915=== PAUSE TestGlobMatch/foo*bar_foobarbaz2916=== RUN TestGlobMatch/*/*_foo/bar2917=== PAUSE TestGlobMatch/*/*_foo/bar2918=== RUN TestGlobMatch/*/*_foo2919=== PAUSE TestGlobMatch/*/*_foo2920=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2921=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2922=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02923=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02924=== RUN TestGlobMatch/refs/*/main_refs/heads/main2925=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2926=== RUN TestGlobMatch/fo?_foo2927=== PAUSE TestGlobMatch/fo?_foo2928=== RUN TestGlobMatch/fo?_fo2929=== PAUSE TestGlobMatch/fo?_fo2930=== RUN TestGlobMatch/fo?_fooo2931=== PAUSE TestGlobMatch/fo?_fooo2932=== RUN TestGlobMatch/?oo_foo2933=== PAUSE TestGlobMatch/?oo_foo2934=== RUN TestGlobMatch/?oo_boo2935=== PAUSE TestGlobMatch/?oo_boo2936=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2937=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2938=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2939=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2940=== CONT TestGlobMatch/foo_foo2941=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02942=== CONT TestGlobMatch/foo*_foobar2943=== CONT TestGlobMatch/foo*bar_foobar2944=== CONT TestGlobMatch/*_anything2945=== CONT TestGlobMatch/*_2946=== CONT TestGlobMatch/foo_bar2947=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2948=== CONT TestGlobMatch/*/*_foo2949=== CONT TestGlobMatch/*/*_foo/bar2950=== CONT TestGlobMatch/foo*bar_foobarbaz2951=== CONT TestGlobMatch/fo?_fo2952=== CONT TestGlobMatch/fo?_fooo2953=== CONT TestGlobMatch/fo?_foo2954=== CONT TestGlobMatch/refs/*/main_refs/heads/main2955=== CONT TestGlobMatch/foo*bar_foo123bar2956=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2957=== CONT TestGlobMatch/?oo_boo2958=== CONT TestGlobMatch/*bar_foo2959=== CONT TestGlobMatch/*bar_foobar2960=== CONT TestGlobMatch/*bar_bar2961=== CONT TestGlobMatch/foo*_bar2962=== CONT TestGlobMatch/?oo_foo2963=== CONT TestGlobMatch/foo*_foo2964=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2965--- PASS: TestGlobMatch (0.00s)2966 --- PASS: TestGlobMatch/foo_foo (0.00s)2967 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2968 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2969 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2970 --- PASS: TestGlobMatch/*_anything (0.00s)2971 --- PASS: TestGlobMatch/*_ (0.00s)2972 --- PASS: TestGlobMatch/foo_bar (0.00s)2973 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2974 --- PASS: TestGlobMatch/*/*_foo (0.00s)2975 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2976 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2977 --- PASS: TestGlobMatch/fo?_fo (0.00s)2978 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2979 --- PASS: TestGlobMatch/fo?_foo (0.00s)2980 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2981 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2982 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2983 --- PASS: TestGlobMatch/?oo_boo (0.00s)2984 --- PASS: TestGlobMatch/*bar_foo (0.00s)2985 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2986 --- PASS: TestGlobMatch/*bar_bar (0.00s)2987 --- PASS: TestGlobMatch/foo*_bar (0.00s)2988 --- PASS: TestGlobMatch/?oo_foo (0.00s)2989 --- PASS: TestGlobMatch/foo*_foo (0.00s)2990 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)29912026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37329/oidc2992--- PASS: TestValidateToken_Expired (0.05s)29932026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36107/oidc29942026/10/01 07:34:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:386412995--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2996--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)29972026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41663/oidc2998--- PASS: TestPins_TopLevelShorthand (0.13s)29992026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39715/oidc3000--- PASS: TestPins_ReservedForMatchingRule (0.14s)30012026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46317/oidc3002--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)30032026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35147/oidc3004--- PASS: TestValidateToken_WrongAudience (0.16s)30052026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44151/oidc3006--- PASS: TestValidateToken_ValidToken (0.20s)30072026/10/01 07:34:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233008--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.24s)30092026/10/01 07:34:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37031/oidc30102026/10/01 07:34:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44755/oidc3011--- PASS: TestValidateToken_MultipleProviders (0.26s)30122026/10/01 07:34:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43497/oidc3013--- PASS: TestValidateToken_NoMatchingProvider (0.35s)30142026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33367/oidc3015--- PASS: TestValidateToken_BoundClaimsMismatch (0.37s)30162026/10/01 07:34:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35007/oidc30172026/10/01 07:34:00 http: TLS handshake error from 127.0.0.1:43216: remote error: tls: bad certificate3018--- PASS: TestNewValidator_KubernetesRequiresCA (0.39s)3019--- PASS: TestScopes_Rules (0.40s)3020PASS3021Running hook tests...3022=== RUN TestSendPathsEmpty3023=== PAUSE TestSendPathsEmpty3024=== RUN TestQueueEnqueueAndFetch3025=== PAUSE TestQueueEnqueueAndFetch3026=== RUN TestQueueDeduplication3027=== PAUSE TestQueueDeduplication3028=== RUN TestQueueRemove3029=== PAUSE TestQueueRemove3030=== RUN TestQueueFetchBatchLimit3031=== PAUSE TestQueueFetchBatchLimit3032=== RUN TestQueueRetryMovesToBack3033=== PAUSE TestQueueRetryMovesToBack3034=== RUN TestQueueFetchRemoveLifecycle3035=== PAUSE TestQueueFetchRemoveLifecycle3036=== RUN TestQueueConcurrentWriters3037=== PAUSE TestQueueConcurrentWriters3038=== RUN TestQueueRemoveLargeClosure3039=== PAUSE TestQueueRemoveLargeClosure3040=== RUN TestServerClientIntegration3041=== PAUSE TestServerClientIntegration3042=== RUN TestServerQueueError3043=== PAUSE TestServerQueueError3044=== RUN TestGetListenerSocketActivation3045 server_test.go:210: === RUN TestGetListenerSocketActivation3046 --- PASS: TestGetListenerSocketActivation (0.00s)3047 PASS3048 3049--- PASS: TestGetListenerSocketActivation (0.01s)3050=== RUN TestDrainIsolatesPoisonPath3051=== PAUSE TestDrainIsolatesPoisonPath3052=== RUN TestRunNotBlockedByPoisonHead3053=== PAUSE TestRunNotBlockedByPoisonHead3054=== RUN TestDrainGivesUpWhenServerDown3055=== PAUSE TestDrainGivesUpWhenServerDown3056=== RUN TestFailedPathPrunedByLaterClosure3057=== PAUSE TestFailedPathPrunedByLaterClosure3058=== RUN TestWorkerUploadsAndRemoves3059=== PAUSE TestWorkerUploadsAndRemoves3060=== RUN TestWorkerSkipsGCdPaths3061=== PAUSE TestWorkerSkipsGCdPaths3062=== RUN TestWorkerPrunesClosureDeps3063=== PAUSE TestWorkerPrunesClosureDeps3064=== RUN TestDrainTimeout3065=== PAUSE TestDrainTimeout3066=== CONT TestSendPathsEmpty3067=== CONT TestDrainGivesUpWhenServerDown3068=== CONT TestWorkerSkipsGCdPaths3069=== CONT TestDrainTimeout3070=== CONT TestQueueFetchRemoveLifecycle3071=== CONT TestQueueRetryMovesToBack3072=== CONT TestQueueFetchBatchLimit3073=== CONT TestQueueRemove3074=== CONT TestQueueDeduplication3075=== CONT TestQueueEnqueueAndFetch3076=== CONT TestQueueConcurrentWriters3077=== CONT TestRunNotBlockedByPoisonHead3078=== CONT TestDrainIsolatesPoisonPath3079=== CONT TestServerQueueError3080=== CONT TestServerClientIntegration3081=== CONT TestQueueRemoveLargeClosure3082=== CONT TestWorkerUploadsAndRemoves3083=== CONT TestFailedPathPrunedByLaterClosure3084=== CONT TestWorkerPrunesClosureDeps3085--- PASS: TestSendPathsEmpty (0.00s)30862026/10/01 07:34:00 ERROR Failed to queue paths error="permission denied" count=13087--- PASS: TestServerQueueError (0.00s)3088--- PASS: TestServerClientIntegration (0.00s)30892026/10/01 07:34:00 INFO Upload queue status pending=230902026/10/01 07:34:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1113144394/002/nonexistent30912026/10/01 07:34:00 INFO Upload queue status pending=230922026/10/01 07:34:00 INFO Uploading batch count=130932026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=130942026/10/01 07:34:00 INFO Uploading batch count=430952026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=430962026/10/01 07:34:00 INFO Uploading batch count=23097--- PASS: TestQueueDeduplication (0.01s)30982026/10/01 07:34:00 INFO Upload queue status pending=33099--- PASS: TestQueueFetchBatchLimit (0.01s)31002026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath244768877/002/bbb3101--- PASS: TestQueueFetchRemoveLifecycle (0.01s)31022026/10/01 07:34:00 INFO Uploading batch count=131032026/10/01 07:34:00 INFO Uploading batch count=131042026/10/01 07:34:00 INFO Uploading batch count=131052026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=13106--- PASS: TestQueueRetryMovesToBack (0.01s)31072026/10/01 07:34:00 INFO Uploading batch count=231082026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=231092026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4244527521/002/a31102026/10/01 07:34:00 INFO Uploading batch count=13111--- PASS: TestQueueRemove (0.01s)31122026/10/01 07:34:00 INFO Upload queue status pending=231132026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4244527521/002/b31142026/10/01 07:34:00 INFO Uploading batch count=131152026/10/01 07:34:00 INFO Uploading batch count=23116--- PASS: TestQueueEnqueueAndFetch (0.01s)31172026/10/01 07:34:00 INFO Uploading batch count=131182026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=131192026/10/01 07:34:00 INFO Uploading batch count=231202026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=231212026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4244527521/002/c31222026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4244527521/002/d31232026/10/01 07:34:00 INFO Uploading batch count=131242026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=131252026/10/01 07:34:00 INFO Uploading batch count=231262026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=231272026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4244527521/002/e31282026/10/01 07:34:00 INFO Uploading batch count=131292026/10/01 07:34:00 ERROR Upload failed error="upload failed" count=13130--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)31312026/10/01 07:34:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4244527521/002/f31322026/10/01 07:34:00 ERROR Drain finished with paths left in queue remaining=131332026/10/01 07:34:00 ERROR Drain finished with paths left in queue remaining=103134--- PASS: TestDrainIsolatesPoisonPath (0.02s)3135--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3136--- PASS: TestWorkerSkipsGCdPaths (0.03s)3137--- PASS: TestWorkerPrunesClosureDeps (0.03s)3138--- PASS: TestWorkerUploadsAndRemoves (0.03s)3139--- PASS: TestQueueRemoveLargeClosure (0.15s)3140--- PASS: TestQueueConcurrentWriters (0.15s)31412026/10/01 07:34:00 ERROR Upload failed error="context deadline exceeded" count=231422026/10/01 07:34:00 ERROR Drain finished with paths left in queue remaining=43143--- PASS: TestDrainTimeout (0.21s)31442026/10/01 07:34:01 INFO Uploading batch count=131452026/10/01 07:34:01 INFO Uploading batch count=131462026/10/01 07:34:01 INFO Uploading batch count=131472026/10/01 07:34:01 ERROR Upload failed error="upload failed" count=131482026/10/01 07:34:01 INFO Uploading batch count=131492026/10/01 07:34:01 ERROR Upload failed error="upload failed" count=131502026/10/01 07:34:01 INFO Uploading batch count=131512026/10/01 07:34:01 ERROR Upload failed error="upload failed" count=131522026/10/01 07:34:01 INFO Uploading batch count=131532026/10/01 07:34:01 ERROR Upload failed error="upload failed" count=131542026/10/01 07:34:01 ERROR Drain finished with paths left in queue remaining=13155--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3156PASS