niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #329 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestShellSplit98=== CONT TestScriptTokenEmptyCommand99--- PASS: TestScriptTokenEmptyCommand (0.00s)100=== CONT TestEncodeNixBase32WithRealHash101--- PASS: TestEncodeNixBase32WithRealHash (0.00s)102=== CONT TestSetClientTLS103=== CONT TestSetClientTLSDoesNotMutateDefaultTransport104--- PASS: TestShellSplit (0.00s)105=== CONT TestResolveStorePath106=== CONT TestScriptTokenBadJSON107=== CONT TestParsePathInfoJSON108=== RUN TestParsePathInfoJSON/Nix_format109=== PAUSE TestParsePathInfoJSON/Nix_format110=== CONT TestScriptTokenEmptyToken111=== CONT TestPathInfoHashCompatibility112=== CONT TestScriptTokenCachesUntilRefresh113=== CONT TestGetStorePathHash114=== RUN TestGetStorePathHash/valid_store_path115=== CONT TestScriptTokenNoExpiryRerunsEveryCall116=== CONT TestConvertHashToNix32117=== CONT TestFileTokenEmpty118=== CONT TestFileTokenMissing119=== CONT TestRateLimiterFeedback120=== CONT TestFileTokenReadsAndCaches121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122=== CONT TestStaticToken123=== CONT TestPathInfoCACompatibility124=== RUN TestPathInfoCACompatibility/null_ca_field125=== CONT TestSetClientTLSErrors1262026/10/01 10:02:59 WARN Rate limiter enabled after throttle name=server-test rate=5127=== CONT TestDoWithRetry_BodyReplayedViaGetBody128=== CONT TestStreamPushGivesUpOnDeadServer129=== CONT TestStreamPushBatchesUnderLoad130=== RUN TestParsePathInfoJSON/Lix_format131--- PASS: TestScriptTokenScriptFails (0.00s)132=== CONT TestStreamPushIsolatesFailures133=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)134=== PAUSE TestGetStorePathHash/valid_store_path135=== CONT TestClientSignaturesByStorePath136=== RUN TestConvertHashToNix32/SRI_format_to_Nix32137=== RUN TestRateLimiterFeedback/429_enables_limiter138=== CONT TestStreamPushReportsEveryPath139--- PASS: TestResolveStorePath (0.00s)140--- PASS: TestStaticToken (0.00s)141--- PASS: TestFileTokenMissing (0.00s)142--- PASS: TestFileTokenEmpty (0.00s)143--- PASS: TestFileTokenReadsAndCaches (0.00s)144=== PAUSE TestParsePathInfoJSON/Lix_format145=== CONT TestStreamPushRequestLine146=== PAUSE TestPathInfoCACompatibility/null_ca_field147=== CONT TestStreamPushReportsSignatures1482026/10/01 10:02:59 ERROR Upload failed error="connection refused" count=201492026/10/01 10:02:59 ERROR Server seems unavailable, giving up on batch untried=17150=== RUN TestPathInfoCACompatibility/old_string_format_-_text1512026/10/01 10:02:59 ERROR Upload failed error="bad path" count=3152=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32153=== RUN TestConvertHashToNix32/already_Nix32_format154=== PAUSE TestConvertHashToNix32/already_Nix32_format155=== RUN TestConvertHashToNix32/invalid_format156=== PAUSE TestConvertHashToNix32/invalid_format157=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text158=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive159=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive160=== RUN TestPathInfoCACompatibility/new_structured_format_-_text161=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text162=== CONT TestDumpPathWriterError163=== CONT TestUploadMultipart_SupersededByPeer1642026/10/01 10:02:59 ERROR Upload failed error=boom count=1165=== CONT TestDumpPathSingleFile1662026/10/01 10:02:59 ERROR Upload failed error=boom count=1167=== CONT TestDumpPathMatchesNix168=== CONT TestPartSizeForNAR169=== CONT TestRegisterUploadedObjectReusesConnections170=== RUN TestPartSizeForNAR/zero_stays_at_minimum171=== CONT TestUploadMultipart_PartsInParallel172=== CONT TestShellSplitErrors173=== RUN TestGetStorePathHash/basename_without_hyphen_should_error174=== PAUSE TestRateLimiterFeedback/429_enables_limiter175=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)176=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method177=== CONT TestEncodeNixBase32178=== RUN TestParsePathInfoJSON/empty_input179=== CONT TestFilterOversizedClosures180=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum181--- PASS: TestClientSignaturesByStorePath (0.00s)182--- PASS: TestStreamPushReportsEveryPath (0.00s)183=== RUN TestUploadMultipart_SupersededByPeer/exists184=== RUN TestPartSizeForNAR/small_stays_at_minimum185=== RUN TestSetClientTLSErrors/missing_cert_file186=== CONT TestCaseHackSuffix187=== RUN TestEncodeNixBase32/test_string_hash188=== RUN TestSetClientTLS/rejects_connection_without_client_cert189=== CONT TestParsePathInfoJSONMultiplePaths190=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error191=== RUN TestRateLimiterFeedback/503_enables_limiter192=== PAUSE TestSetClientTLSErrors/missing_cert_file193=== RUN TestSetClientTLSErrors/missing_key_file194=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon195=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon196=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI198=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512199=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method200=== PAUSE TestParsePathInfoJSON/empty_input201=== RUN TestFilterOversizedClosures/no_limit_keeps_everything202--- PASS: TestStreamPushIsolatesFailures (0.00s)203=== PAUSE TestUploadMultipart_SupersededByPeer/exists204=== PAUSE TestRateLimiterFeedback/503_enables_limiter205=== RUN TestParsePathInfoJSON/whitespace_only206=== PAUSE TestParsePathInfoJSON/whitespace_only207=== RUN TestParsePathInfoJSON/invalid_JSON208=== PAUSE TestParsePathInfoJSON/invalid_JSON209--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)210=== CONT TestConvertHashToNix32/already_Nix32_format211=== CONT TestConvertHashToNix32/invalid_format2122026/10/01 10:02:59 WARN Rate limiter enabled after throttle name=server-test rate=5213=== CONT TestPathInfoCACompatibility/null_ca_field2142026/10/01 10:02:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37489215=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method216=== CONT TestConvertHashToNix32/SRI_format_to_Nix322172026/10/01 10:02:59 WARN Rate limiter backed off name=server-test rate=52182026/10/01 10:02:59 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37489219=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter220=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter221=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512222=== RUN TestUploadMultipart_SupersededByPeer/missing223=== PAUSE TestUploadMultipart_SupersededByPeer/missing224=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything225=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped226=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped227=== RUN TestFilterOversizedClosures/all_closures_skipped228=== PAUSE TestFilterOversizedClosures/all_closures_skipped229--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)230=== CONT TestParsePathInfoJSON/empty_input231=== CONT TestParsePathInfoJSON/invalid_JSON232=== CONT TestParsePathInfoJSON/Lix_format233--- PASS: TestScriptTokenBadJSON (0.01s)234--- PASS: TestDoServerRequestAttachesToken (0.01s)235=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)237=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512238=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI239=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon240=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths241=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths242=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths243=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths244=== CONT TestUploadMultipart_SupersededByPeer/exists245=== PAUSE TestEncodeNixBase32/test_string_hash246=== RUN TestEncodeNixBase32/empty_input247=== PAUSE TestEncodeNixBase32/empty_input248=== CONT TestFilterOversizedClosures/all_closures_skipped249=== PAUSE TestSetClientTLSErrors/missing_key_file250=== RUN TestSetClientTLSErrors/missing_ca_file251=== PAUSE TestSetClientTLSErrors/missing_ca_file2522026/10/01 10:02:59 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=50253=== CONT TestParsePathInfoJSON/Nix_format254=== CONT TestFilterOversizedClosures/no_limit_keeps_everything255=== CONT TestEncodeNixBase32/test_string_hash256=== CONT TestEncodeNixBase32/empty_input257=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths258=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error259=== CONT TestParsePathInfoJSON/whitespace_only260=== CONT TestPathInfoCACompatibility/new_structured_format_-_text261--- PASS: TestStreamPushReportsSignatures (0.00s)262--- PASS: TestScriptTokenEmptyToken (0.00s)263--- PASS: TestShellSplitErrors (0.00s)264=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter265=== CONT TestPathInfoCACompatibility/old_string_format_-_text266=== CONT TestUploadMultipart_SupersededByPeer/missing267=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert268=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter269=== CONT TestRateLimiterFeedback/429_enables_limiter270=== PAUSE TestPartSizeForNAR/small_stays_at_minimum271=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum272=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum273=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts274=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts275=== RUN TestPartSizeForNAR/1_TiB276=== PAUSE TestPartSizeForNAR/1_TiB277--- PASS: TestConvertHashToNix32 (0.00s)278 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)279 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)280 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)281=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA282=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA283--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)284=== RUN TestSetClientTLS/preserves_debug_logging_transport285=== PAUSE TestSetClientTLS/preserves_debug_logging_transport286=== CONT TestSetClientTLS/rejects_connection_without_client_cert287--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)288 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)289 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)290=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error291=== RUN TestPartSizeForNAR/5_TiB_S3_max_object292=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object293=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA294--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)2952026/10/01 10:02:59 WARN Rate limiter enabled after throttle name=server-test rate=5296--- PASS: TestEncodeNixBase32 (0.03s)297 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)298 --- PASS: TestEncodeNixBase32/empty_input (0.00s)2992026/10/01 10:02:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39747300=== CONT TestSetClientTLS/preserves_debug_logging_transport301=== RUN TestPartSizeForNAR/capped_at_5_GiB302=== PAUSE TestPartSizeForNAR/capped_at_5_GiB303=== CONT TestPartSizeForNAR/zero_stays_at_minimum304=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3052026/10/01 10:02:59 WARN Rate limiter backed off name=server-test rate=5306=== CONT TestPartSizeForNAR/capped_at_5_GiB307=== CONT TestPartSizeForNAR/5_TiB_S3_max_object308=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error309=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error310=== CONT TestGetStorePathHash/valid_store_path311=== CONT TestPartSizeForNAR/1_TiB312=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts313=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum314=== CONT TestPartSizeForNAR/small_stays_at_minimum315=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3162026/10/01 10:02:59 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=2000317=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths318=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error319=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error320=== CONT TestRateLimiterFeedback/503_enables_limiter321=== RUN TestSetClientTLSErrors/invalid_ca_file322--- PASS: TestParsePathInfoJSON (0.04s)323 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)324 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)325 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)326 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)327 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)328--- PASS: TestPathInfoCACompatibility (0.04s)329 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)330 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)331 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)332 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)333 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)334=== PAUSE TestSetClientTLSErrors/invalid_ca_file335=== CONT TestSetClientTLSErrors/missing_cert_file336=== CONT TestGetStorePathHash/basename_without_hyphen_should_error337=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter338--- PASS: TestPathInfoHashCompatibility (0.04s)339 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)340 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)341 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)342 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)343=== CONT TestSetClientTLSErrors/invalid_ca_file344=== CONT TestSetClientTLSErrors/missing_key_file345--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)346=== CONT TestSetClientTLSErrors/missing_ca_file347--- PASS: TestFilterOversizedClosures (0.03s)348 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)349 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)350 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3512026/10/01 10:02:59 WARN Rate limiter enabled after throttle name=server-test rate=5352--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)353 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)354 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)3552026/10/01 10:02:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35475356--- PASS: TestGetStorePathHash (0.04s)357 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)359 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)3612026/10/01 10:02:59 WARN Rate limiter backed off name=server-test rate=5362--- PASS: TestPartSizeForNAR (0.04s)363 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)365 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)366 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)370--- PASS: TestRateLimiterFeedback (0.04s)371 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)374 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)375--- PASS: TestSetClientTLSErrors (0.04s)376 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)378 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3802026/10/01 10:02:59 http: TLS handshake error from 127.0.0.1:39016: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.04s)382 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)385--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)386--- PASS: TestDumpPathSingleFile (0.07s)387--- PASS: TestCaseHackSuffix (0.03s)388--- PASS: TestStreamPushRequestLine (0.07s)389--- PASS: TestDumpPathWriterError (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres2446521043/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/postgres2446521043/data -l logfile start422423/build/postgres2446521043:5432 - no response4242026-10-01 10:03:01.630 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:03:01.630 UTC [128] LOG: listening on Unix socket "/build/postgres2446521043/.s.PGSQL.5432"4262026-10-01 10:03:01.637 UTC [135] LOG: database system was shut down at 2026-10-01 10:03:01 UTC4272026-10-01 10:03:01.641 UTC [128] LOG: database system is ready to accept connections428/build/postgres2446521043:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestLeadElectsOneAndHandsOver470=== PAUSE TestLeadElectsOneAndHandsOver471=== RUN TestLeadIncumbentWinsAfterRestart4722026-10-01 10:03:01.910 UTC [372] ERROR: relation "goose_db_version" does not exist at character 364732026-10-01 10:03:01.910 UTC [372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/10/01 10:03:01 OK 20241026095416_initial_model.sql (10.91ms)4752026/10/01 10:03:01 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)4762026/10/01 10:03:01 OK 20251218171726_add_pins.sql (2.62ms)4772026/10/01 10:03:01 OK 20260628120000_add_object_size_and_stats.sql (2.6ms)4782026/10/01 10:03:01 OK 20260905000000_add_claims.sql (2.97ms)4792026/10/01 10:03:01 OK 20260920000000_drop_claims.sql (1.86ms)4802026/10/01 10:03:01 OK 20260923120000_add_pushes.sql (1.44ms)4812026/10/01 10:03:01 goose: successfully migrated database to version: 202609231200004822026/10/01 10:03:01 OK 1_commit_pending_closure.sql (1.61ms)4832026/10/01 10:03:01 OK 2_object_stats_trigger.sql (784.85µs)4842026/10/01 10:03:01 OK 3_commit_push.sql (556.17µs)4852026/10/01 10:03:01 goose: up to current file version: 34862026/10/01 10:03:01 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 10:03:02 INFO lead: released remote=192.0.2.1:12344882026/10/01 10:03:02 INFO lead: acquired remote=192.0.2.1:12344892026/10/01 10:03:02 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestGCAdvisoryLockBlocksConcurrentRun4942026-10-01 10:03:02.675 UTC [382] ERROR: relation "goose_db_version" does not exist at character 364952026-10-01 10:03:02.675 UTC [382] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4962026/10/01 10:03:02 OK 20241026095416_initial_model.sql (9.68ms)4972026/10/01 10:03:02 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)4982026/10/01 10:03:02 OK 20251218171726_add_pins.sql (3.06ms)4992026/10/01 10:03:02 OK 20260628120000_add_object_size_and_stats.sql (3.1ms)5002026/10/01 10:03:02 OK 20260905000000_add_claims.sql (2.86ms)5012026/10/01 10:03:02 OK 20260920000000_drop_claims.sql (1.91ms)5022026/10/01 10:03:02 OK 20260923120000_add_pushes.sql (1.37ms)5032026/10/01 10:03:02 goose: successfully migrated database to version: 202609231200005042026/10/01 10:03:02 OK 1_commit_pending_closure.sql (1.79ms)5052026/10/01 10:03:02 OK 2_object_stats_trigger.sql (667.13µs)5062026/10/01 10:03:02 OK 3_commit_push.sql (513.61µs)5072026/10/01 10:03:02 goose: up to current file version: 3508--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestOrphanedObjectsGC588=== PAUSE TestOrphanedObjectsGC589=== RUN TestOrphanedObjectsGCStressTest590=== PAUSE TestOrphanedObjectsGCStressTest591=== RUN TestCreatePin_ReservedPins592=== PAUSE TestCreatePin_ReservedPins593=== RUN TestPresentReportsOnlyClosureRoots594=== PAUSE TestPresentReportsOnlyClosureRoots595=== RUN TestPresentNotReportedWhileGCDeletesClosure596=== PAUSE TestPresentNotReportedWhileGCDeletesClosure597=== RUN TestParseSingleRange598=== PAUSE TestParseSingleRange599=== RUN TestProxyHeadersOnlyTrustedOnSocket600=== PAUSE TestProxyHeadersOnlyTrustedOnSocket601=== RUN TestIsValidCachePath602=== PAUSE TestIsValidCachePath603=== RUN TestReadProxyNarinfo604=== PAUSE TestReadProxyNarinfo605=== RUN TestReadProxyNarinfoAlreadyDecompressed606=== PAUSE TestReadProxyNarinfoAlreadyDecompressed607=== RUN TestReadProxyNarStreaming608=== PAUSE TestReadProxyNarStreaming609=== RUN TestReadProxy404610=== PAUSE TestReadProxy404611=== RUN TestReadProxyInvalidPath612=== PAUSE TestReadProxyInvalidPath613=== RUN TestReadProxyHead614=== PAUSE TestReadProxyHead615=== RUN TestReadProxyConditionalGet616=== PAUSE TestReadProxyConditionalGet617=== RUN TestReadProxyRootRedirectsToIndexHTML618=== PAUSE TestReadProxyRootRedirectsToIndexHTML619=== RUN TestReadProxyDisabled620=== PAUSE TestReadProxyDisabled621=== RUN TestReadRedirectNar622=== PAUSE TestReadRedirectNar623=== RUN TestReadRedirectKeepsNarinfoProxied624=== PAUSE TestReadRedirectKeepsNarinfoProxied625=== RUN TestReadProxyRangeRequest626=== PAUSE TestReadProxyRangeRequest627=== RUN TestReadRedirectUsesPublicS3URL628=== PAUSE TestReadRedirectUsesPublicS3URL629=== RUN TestPush_OverlappingRootsStoreOneRowPerKey630=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey631=== RUN TestPush_CompleteCommitsEveryRoot632=== PAUSE TestPush_CompleteCommitsEveryRoot633=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit634=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit635=== RUN TestPush_RejectsBadRequests636=== PAUSE TestPush_RejectsBadRequests637=== RUN TestPush_SignsNarinfosOfItsPendingObjects638=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects639=== RUN TestRedundantMultipartUpload640=== PAUSE TestRedundantMultipartUpload641=== RUN TestCompleteMultipartUpload_ErrorButObjectExists642=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists643=== RUN TestCompletedNarNotReofferedAcrossClosures644=== PAUSE TestCompletedNarNotReofferedAcrossClosures645=== RUN TestPresignedUploadRegisteredBeforeCommit646=== PAUSE TestPresignedUploadRegisteredBeforeCommit647=== RUN TestService_Rustfstest648=== PAUSE TestService_Rustfstest649=== RUN TestParseSize650=== PAUSE TestParseSize651=== RUN TestSkippedUploadsHandler652=== PAUSE TestSkippedUploadsHandler653=== RUN TestSystemdListenerNotActivated654--- PASS: TestSystemdListenerNotActivated (0.00s)655=== RUN TestWatchdogBeatsWhenHealthy656--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)657=== RUN TestWatchdogSkipsWhenUnhealthy6582026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:03:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"668--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)669=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== RUN TestProxyWriteTimeout672=== PAUSE TestProxyWriteTimeout673=== RUN TestIsValidUploadKey674=== PAUSE TestIsValidUploadKey675=== RUN TestUploadHandlersRejectInvalidKeys676=== PAUSE TestUploadHandlersRejectInvalidKeys677=== RUN TestUploadHandlersRejectOversizedBody678=== PAUSE TestUploadHandlersRejectOversizedBody679=== RUN TestService_cleanupPendingClosuresHandler680=== PAUSE TestService_cleanupPendingClosuresHandler681=== RUN TestService_createPendingClosureHandler682=== PAUSE TestService_createPendingClosureHandler683=== RUN TestService_verifyS3Integrity684=== PAUSE TestService_verifyS3Integrity685=== RUN TestCompleteMultipartUnregistered686=== PAUSE TestCompleteMultipartUnregistered687=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT688=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT689=== CONT TestProxyWriteTimeout690=== RUN TestProxyWriteTimeout/narinfo691=== CONT TestService_AuthMiddleware692=== CONT TestGracefulShutdownDrainsInflight693=== CONT TestGCTaskStore_Fail694--- PASS: TestGCTaskStore_Fail (0.00s)695=== CONT TestClientFallsBackToClosures696=== CONT TestService_healthCheckHandler697=== CONT TestGCTaskStore_PhaseUpdates698--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)6992026/10/01 10:03:02 INFO Starting HTTP server address=127.0.0.1:45841700=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit701=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle702=== CONT TestGCTaskStore_CompletedAllowsNewTask703--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)704=== CONT TestClientPushesUseOnePush705=== CONT TestSkippedUploadsHandler706=== CONT TestGCTaskStore_GetReturnsLatest707--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)708=== CONT TestPush_CompleteCommitsEveryRoot709=== CONT TestParseSize710--- PASS: TestParseSize (0.00s)711=== CONT TestPinProtectsFromGC7122026/10/01 10:03:02 INFO Shutdown signal received, draining in-flight requests timeout=10s713=== CONT TestGCTaskStore_GetEmpty714--- PASS: TestGCTaskStore_GetEmpty (0.00s)715=== CONT TestPush_OverlappingRootsStoreOneRowPerKey716=== CONT TestService_Rustfstest717=== CONT TestGCTaskStore_ConflictDifferentParams7182026/10/01 10:03:02 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000719--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)720=== CONT TestPresignedUploadRegisteredBeforeCommit721=== CONT TestGCTaskStore_DeduplicateSameParams722=== CONT TestCompletedNarNotReofferedAcrossClosures723=== CONT TestGCTaskStore_StartNew724=== CONT TestCompleteMultipartUpload_ErrorButObjectExists725=== CONT TestGCEndsOnShutdown726=== CONT TestRedundantMultipartUpload727=== CONT TestPush_SignsNarinfosOfItsPendingObjects728=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock729=== CONT TestPush_RejectsBadRequests730=== PAUSE TestProxyWriteTimeout/narinfo731=== CONT TestResolveDBConnectionString732=== RUN TestResolveDBConnectionString/flag_wins733=== PAUSE TestResolveDBConnectionString/flag_wins734=== RUN TestResolveDBConnectionString/file_when_flag_empty735=== PAUSE TestResolveDBConnectionString/file_when_flag_empty736=== RUN TestResolveDBConnectionString/missing_file_is_an_error737=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error738=== RUN TestResolveDBConnectionString/PGHOST_allows_empty739=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty740=== RUN TestResolveDBConnectionString/nothing_configured741=== PAUSE TestResolveDBConnectionString/nothing_configured742--- PASS: TestGCTaskStore_StartNew (0.00s)743=== CONT TestClientSharedPathCommittedMidPush744=== RUN TestProxyWriteTimeout/1_GiB_nar745=== PAUSE TestProxyWriteTimeout/1_GiB_nar746=== RUN TestProxyWriteTimeout/10_GiB_nar747=== PAUSE TestProxyWriteTimeout/10_GiB_nar748=== CONT TestCommitRacingPendingCleanupKeepsObjects749--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)750=== CONT TestPushWaitsForSweepHoldingRow751=== RUN TestProxyWriteTimeout/unknown_size752=== PAUSE TestProxyWriteTimeout/unknown_size753=== CONT TestClientWithDependencies754--- PASS: TestSkippedUploadsHandler (0.01s)755=== CONT TestClientMultipleUploads756--- PASS: TestGracefulShutdownDrainsInflight (0.07s)757=== CONT TestClientIntegration7582026-10-01 10:03:03.072 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367592026-10-01 10:03:03.072 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026-10-01 10:03:03.072 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367612026-10-01 10:03:03.072 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026-10-01 10:03:03.087 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367632026-10-01 10:03:03.087 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7642026-10-01 10:03:03.116 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367652026-10-01 10:03:03.116 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7662026/10/01 10:03:03 OK 20241026095416_initial_model.sql (26.94ms)7672026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)7682026-10-01 10:03:03.134 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367692026-10-01 10:03:03.134 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026-10-01 10:03:03.134 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367712026-10-01 10:03:03.134 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7722026/10/01 10:03:03 OK 20241026095416_initial_model.sql (26.79ms)7732026/10/01 10:03:03 OK 20241026095416_initial_model.sql (26.52ms)7742026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)7752026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.76ms)7762026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)7772026-10-01 10:03:03.147 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367782026-10-01 10:03:03.147 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026/10/01 10:03:03 OK 20251218171726_add_pins.sql (12.79ms)7802026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (14.54ms)7812026/10/01 10:03:03 OK 20251218171726_add_pins.sql (15.38ms)7822026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (7.02ms)7832026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.97ms)7842026/10/01 10:03:03 OK 20241026095416_initial_model.sql (26.2ms)7852026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.57ms)7862026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.04ms)7872026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.51ms)7882026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)7892026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.85ms)7902026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200007912026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.93ms)7922026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.95ms)7932026-10-01 10:03:03.165 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367942026-10-01 10:03:03.165 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-10-01 10:03:03.166 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367962026-10-01 10:03:03.166 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-10-01 10:03:03.167 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367982026-10-01 10:03:03.167 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-10-01 10:03:03.167 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368002026-10-01 10:03:03.167 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/10/01 10:03:03 OK 20241026095416_initial_model.sql (22.97ms)8022026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.42ms)8032026-10-01 10:03:03.167 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368042026-10-01 10:03:03.167 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026/10/01 10:03:03 OK 1_commit_pending_closure.sql (4.1ms)8062026/10/01 10:03:03 OK 20251218171726_add_pins.sql (138.74ms)8072026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (136.61ms)8082026/10/01 10:03:03 OK 2_object_stats_trigger.sql (135.35ms)8092026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (137.8ms)8102026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200008112026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (136.57ms)8122026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (136.6ms)8132026/10/01 10:03:03 OK 3_commit_push.sql (3.39ms)8142026/10/01 10:03:03 goose: up to current file version: 38152026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (5.65ms)8162026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200008172026/10/01 10:03:03 OK 1_commit_pending_closure.sql (4.33ms)8182026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.55ms)8192026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.49ms)8202026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (7.7ms)8212026/10/01 10:03:03 OK 20241026095416_initial_model.sql (150.11ms)8222026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.24ms)8232026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.02ms)8242026/10/01 10:03:03 OK 3_commit_push.sql (1.72ms)8252026/10/01 10:03:03 goose: up to current file version: 38262026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)8272026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.09ms)8282026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.42ms)8292026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)8302026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)8312026/10/01 10:03:03 OK 3_commit_push.sql (1.87ms)8322026/10/01 10:03:03 goose: up to current file version: 38332026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.31ms)8342026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.68ms)8352026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.62ms)8362026/10/01 10:03:03 OK 20260905000000_add_claims.sql (5.32ms)8372026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.35ms)8382026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200008392026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.37ms)8402026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)8412026/10/01 10:03:03 OK 20241026095416_initial_model.sql (13.67ms)8422026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.8ms)8432026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.38ms)8442026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.83ms)8452026-10-01 10:03:03.325 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368462026-10-01 10:03:03.325 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8472026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.24ms)8482026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.73ms)8492026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.52ms)8502026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200008512026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.5ms)8522026-10-01 10:03:03.327 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368532026-10-01 10:03:03.327 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)8552026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.08ms)8562026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200008572026/10/01 10:03:03 OK 20241026095416_initial_model.sql (15.01ms)8582026-10-01 10:03:03.327 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368592026-10-01 10:03:03.327 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026-10-01 10:03:03.327 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368612026-10-01 10:03:03.327 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8622026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)8632026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.92ms)8642026-10-01 10:03:03.328 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368652026-10-01 10:03:03.328 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8662026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)8672026/10/01 10:03:03 OK 3_commit_push.sql (1.69ms)8682026-10-01 10:03:03.329 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368692026-10-01 10:03:03.329 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/10/01 10:03:03 goose: up to current file version: 38712026-10-01 10:03:03.329 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368722026-10-01 10:03:03.329 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8732026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes8742026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)8752026-10-01 10:03:03.330 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368762026-10-01 10:03:03.330 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8772026-10-01 10:03:03.330 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368782026-10-01 10:03:03.330 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026-10-01 10:03:03.330 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368802026-10-01 10:03:03.330 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8812026-10-01 10:03:03.330 UTC [475] ERROR: relation "goose_db_version" does not exist at character 368822026-10-01 10:03:03.330 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)8842026-10-01 10:03:03.331 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368852026-10-01 10:03:03.331 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8862026/10/01 10:03:03 OK 1_commit_pending_closure.sql (4.37ms)8872026/10/01 10:03:03 OK 1_commit_pending_closure.sql (4.08ms)8882026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.97ms)8892026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (4.74ms)8902026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.29ms)8912026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.2ms)8922026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.38ms)8932026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.83ms)8942026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.64ms)8952026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.65ms)8962026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200008972026/10/01 10:03:03 OK 3_commit_push.sql (1.74ms)8982026/10/01 10:03:03 goose: up to current file version: 38992026/10/01 10:03:03 OK 3_commit_push.sql (2.3ms)9002026/10/01 10:03:03 goose: up to current file version: 39012026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)9022026/10/01 10:03:03 OK 20251218171726_add_pins.sql (6.03ms)9032026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)9042026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)9052026/10/01 10:03:03 OK 1_commit_pending_closure.sql (4.39ms)9062026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (6.18ms)9072026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.42ms)9082026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)9092026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.9ms)9102026/10/01 10:03:03 OK 20260905000000_add_claims.sql (5.02ms)9112026/10/01 10:03:03 OK 3_commit_push.sql (1.44ms)9122026/10/01 10:03:03 goose: up to current file version: 39132026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.48ms)9142026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.98ms)9152026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.98ms)9162026/10/01 10:03:03 OK 20260905000000_add_claims.sql (5.59ms)9172026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.67ms)9182026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.86ms)9192026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200009202026/10/01 10:03:03 OK 20241026095416_initial_model.sql (15.12ms)9212026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (4.15ms)9222026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.31ms)9232026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.33ms)9242026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200009252026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes9262026/10/01 10:03:03 OK 20241026095416_initial_model.sql (15.28ms)9272026/10/01 10:03:03 OK 20241026095416_initial_model.sql (16.29ms)9282026/10/01 10:03:03 OK 20241026095416_initial_model.sql (16.3ms)9292026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.55ms)9302026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200009312026/10/01 10:03:03 OK 20241026095416_initial_model.sql (16.46ms)9322026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (3.63ms)9332026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (5.04ms)9342026/10/01 10:03:03 OK 1_commit_pending_closure.sql (4.77ms)9352026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.33ms)9362026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.72ms)9372026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.42ms)9382026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.49ms)9392026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200009402026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.4ms)941--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.39s)942=== CONT TestSweepRechecksPendingAfterLocking9432026/10/01 10:03:03 OK 20241026095416_initial_model.sql (15.03ms)9442026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.6ms)9452026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.89ms)9462026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.29ms)9472026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)9482026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.42ms)9492026/10/01 10:03:03 OK 20241026095416_initial_model.sql (14.68ms)9502026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)9512026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)9522026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.88ms)9532026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200009542026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.92ms)9552026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)9562026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)9572026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.18ms)9582026/10/01 10:03:03 OK 3_commit_push.sql (1.42ms)9592026/10/01 10:03:03 goose: up to current file version: 39602026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.72ms)9612026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)9622026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)9632026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)9642026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9652026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)9662026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.83ms)9672026/10/01 10:03:03 OK 3_commit_push.sql (938.41µs)9682026/10/01 10:03:03 goose: up to current file version: 39692026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)9702026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.01ms)9712026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.14ms)9722026/10/01 10:03:03 OK 3_commit_push.sql (1.61ms)9732026/10/01 10:03:03 goose: up to current file version: 39742026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.82ms)9752026/10/01 10:03:03 OK 3_commit_push.sql (1.82ms)9762026/10/01 10:03:03 goose: up to current file version: 39772026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.41ms)9782026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.9ms)9792026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.26ms)9802026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.22ms)9812026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.09ms)9822026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.39ms)9832026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.66ms)9842026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.34ms)9852026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.16ms)9862026/10/01 10:03:03 OK 20251218171726_add_pins.sql (5.16ms)9872026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.26ms)9882026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)9892026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)9902026/10/01 10:03:03 OK 3_commit_push.sql (1.63ms)9912026/10/01 10:03:03 goose: up to current file version: 39922026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)9932026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)9942026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)9952026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)9962026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.71ms)9972026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)9982026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.17ms)10002026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.33ms)10012026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.05ms)10022026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.69ms)10032026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.34ms)10042026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.81ms)10052026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)10062026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)10072026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)10082026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)10092026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)10102026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/1/complete10112026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.95ms)10122026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (1.89ms)10132026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010142026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.76ms)10152026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.81ms)10162026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.89ms)10172026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.02ms)10182026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.12ms)10192026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.14ms)10202026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.87ms)10212026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.89ms)10222026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.75ms)10232026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.82ms)10242026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.11ms)10252026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.09ms)10262026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.82ms)10272026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010282026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010292026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.9ms)10302026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010312026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.79ms)10322026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010332026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.7ms)10342026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3ms)10352026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010362026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.89ms)10372026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.31ms)10382026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010392026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.82ms)10402026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.93ms)10412026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (4.1ms)10422026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.32ms)10432026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.93ms)10442026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.17ms)10452026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.03ms)10462026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.33ms)10472026/10/01 10:03:03 OK 3_commit_push.sql (2.61ms)10482026/10/01 10:03:03 goose: up to current file version: 310492026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.55ms)10502026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (1.96ms)10512026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010522026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.03ms)10532026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010542026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.61ms)10552026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes10562026/10/01 10:03:03 OK 2_object_stats_trigger.sql (960.97µs)10572026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.07ms)10582026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (4.08ms)10592026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.24ms)10602026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.2ms)10612026/10/01 10:03:03 OK 2_object_stats_trigger.sql (985.35µs)10622026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (1.83ms)10632026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010642026/10/01 10:03:03 OK 3_commit_push.sql (746.61µs)10652026/10/01 10:03:03 goose: up to current file version: 310662026/10/01 10:03:03 OK 3_commit_push.sql (908.85µs)10672026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.27ms)10682026/10/01 10:03:03 goose: up to current file version: 310692026/10/01 10:03:03 OK 3_commit_push.sql (60.38ms)10702026/10/01 10:03:03 goose: up to current file version: 310712026/10/01 10:03:03 OK 1_commit_pending_closure.sql (60.95ms)10722026/10/01 10:03:03 OK 3_commit_push.sql (60.43ms)10732026/10/01 10:03:03 goose: up to current file version: 310742026/10/01 10:03:03 OK 3_commit_push.sql (61.2ms)10752026/10/01 10:03:03 goose: up to current file version: 310762026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (63.35ms)10772026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010782026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.72ms)10792026/10/01 10:03:03 OK 3_commit_push.sql (62.97ms)10802026/10/01 10:03:03 goose: up to current file version: 310812026/10/01 10:03:03 OK 1_commit_pending_closure.sql (63.66ms)10822026/10/01 10:03:03 OK 1_commit_pending_closure.sql (62.72ms)10832026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (63.7ms)10842026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000010852026-10-01 10:03:03.453 UTC [482] ERROR: relation "goose_db_version" does not exist at character 3610862026-10-01 10:03:03.453 UTC [482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026/10/01 10:03:03 OK 1_commit_pending_closure.sql (15.48ms)10882026/10/01 10:03:03 OK 1_commit_pending_closure.sql (15.83ms)10892026/10/01 10:03:03 OK 2_object_stats_trigger.sql (15.63ms)10902026/10/01 10:03:03 OK 2_object_stats_trigger.sql (15.59ms)10912026/10/01 10:03:03 OK 3_commit_push.sql (15.79ms)10922026/10/01 10:03:03 goose: up to current file version: 310932026/10/01 10:03:03 OK 3_commit_push.sql (916.19µs)10942026/10/01 10:03:03 goose: up to current file version: 310952026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.36ms)10962026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.32ms)10972026/10/01 10:03:03 OK 3_commit_push.sql (1.3ms)10982026/10/01 10:03:03 goose: up to current file version: 310992026/10/01 10:03:03 OK 3_commit_push.sql (633.71µs)11002026/10/01 10:03:03 goose: up to current file version: 311012026/10/01 10:03:03 OK 3_commit_push.sql (714.23µs)11022026/10/01 10:03:03 goose: up to current file version: 311032026/10/01 10:03:03 OK 20241026095416_initial_model.sql (8.85ms)11042026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)11052026/10/01 10:03:03 OK 20251218171726_add_pins.sql (2.7ms)11062026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (2.39ms)11072026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.23ms)11082026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (1.77ms)11092026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (1.54ms)11102026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000011112026/10/01 10:03:03 OK 1_commit_pending_closure.sql (1.58ms)11122026/10/01 10:03:03 OK 2_object_stats_trigger.sql (700.69µs)11132026/10/01 10:03:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"11142026/10/01 10:03:03 OK 3_commit_push.sql (653.87µs)1115--- PASS: TestService_AuthMiddleware (0.53s)11162026/10/01 10:03:03 goose: up to current file version: 31117=== CONT TestClientErrorHandling1118=== RUN TestClientErrorHandling/InvalidStorePath1119=== PAUSE TestClientErrorHandling/InvalidStorePath1120=== RUN TestClientErrorHandling/InvalidAuthToken1121=== PAUSE TestClientErrorHandling/InvalidAuthToken1122=== RUN TestClientErrorHandling/ServerNotAvailable1123=== PAUSE TestClientErrorHandling/ServerNotAvailable1124=== CONT TestGetExistingObjectsLocksRows1125--- PASS: TestService_healthCheckHandler (0.55s)11262026/10/01 10:03:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1127=== CONT TestReadRedirectUsesPublicS3URL11282026/10/01 10:03:03 INFO Aborted multipart uploads count=0 kept=011292026/10/01 10:03:03 WARN Force mode enabled - objects will be deleted immediately without grace period11302026/10/01 10:03:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=011312026/10/01 10:03:03 INFO Vacuumed table table=pending_closures11322026/10/01 10:03:03 INFO Vacuumed table table=pending_objects11332026/10/01 10:03:03 INFO Vacuumed table table=multipart_uploads11342026/10/01 10:03:03 INFO Vacuumed table table=closures11352026/10/01 10:03:03 INFO Vacuumed table table=objects11362026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/2/complete1137=== CONT TestClientCADerivations1138--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.60s)11392026-10-01 10:03:03.565 UTC [525] ERROR: relation "goose_db_version" does not exist at character 3611402026-10-01 10:03:03.565 UTC [525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1141--- PASS: TestGCEndsOnShutdown (0.61s)1142=== CONT TestReadProxyRangeRequest11432026/10/01 10:03:03 OK 20241026095416_initial_model.sql (11.15ms)11442026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)11452026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures11462026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.82ms)11472026-10-01 10:03:03.591 UTC [562] ERROR: relation "goose_db_version" does not exist at character 3611482026-10-01 10:03:03.591 UTC [562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11492026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)11502026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.83ms)11512026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.33ms)11532026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.22ms)11542026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200001155=== NAME TestPinProtectsFromGC1156 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1729877996/001/store/viaq9ki81jp1qv0i2cdmb5kz9l0xi89r-pinned-file.txt1157 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1729877996/001/store/j9w5j7psyrn5q8215880ig5zlh9sgkd9-unpinned-file.txt11582026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.62ms)11592026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.52ms)1160--- PASS: TestService_Rustfstest (0.65s)1161=== CONT TestCacheStatsHandler11622026/10/01 10:03:03 OK 20241026095416_initial_model.sql (9.36ms)11632026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)11642026/10/01 10:03:03 OK 3_commit_push.sql (1.43ms)11652026/10/01 10:03:03 goose: up to current file version: 311662026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.84ms)11672026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (11.2ms)11682026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.11ms)11692026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.78ms)11702026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.01ms)11712026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000011722026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.16ms)11732026-10-01 10:03:03.639 UTC [602] ERROR: relation "goose_db_version" does not exist at character 3611742026-10-01 10:03:03.639 UTC [602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.73ms)11762026/10/01 10:03:03 OK 3_commit_push.sql (1.35ms)11772026/10/01 10:03:03 goose: up to current file version: 311782026-10-01 10:03:03.655 UTC [620] ERROR: relation "goose_db_version" does not exist at character 3611792026-10-01 10:03:03.655 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11802026/10/01 10:03:03 OK 20241026095416_initial_model.sql (11.22ms)11812026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes11822026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)11832026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.89ms)11842026/10/01 10:03:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11852026/10/01 10:03:03 INFO Uploading vcz2ihk35rjsdj01q02synd67kcwcvyd-a (216B)11862026/10/01 10:03:03 INFO Uploading vvk7mj0ll6ml1vw0ddpdzfqkbjjbq4d6-shared-dep (136B)11872026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)11882026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures11892026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11902026/10/01 10:03:03 WARN Failed to register uploaded object key=a08db48wjdrp1i9iq163j7m013s8vhc4.ls error="server returned 404: 404 page not found\n"11912026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.26ms)11922026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/149nzhwglqriqjbjs0r6pp5jgxsifw9b6zfajsg719d7bi7w5v17.nar.zst error="server returned 404: 404 page not found\n"11932026/10/01 10:03:03 WARN Failed to register uploaded object key=vvk7mj0ll6ml1vw0ddpdzfqkbjjbq4d6.ls error="server returned 404: 404 page not found\n"11942026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11952026/10/01 10:03:03 WARN Failed to register uploaded object key=vcz2ihk35rjsdj01q02synd67kcwcvyd.ls error="server returned 404: 404 page not found\n"11962026/10/01 10:03:03 OK 20241026095416_initial_model.sql (12.09ms)11972026/10/01 10:03:03 INFO Signed narinfos id=1 count=311982026/10/01 10:03:03 INFO Uploading 3 narinfos11992026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.69ms)12002026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.43ms)12012026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000012022026/10/01 10:03:03 WARN Failed to register uploaded object key=a08db48wjdrp1i9iq163j7m013s8vhc4.narinfo error="server returned 404: 404 page not found\n"12032026/10/01 10:03:03 WARN Failed to register uploaded object key=vvk7mj0ll6ml1vw0ddpdzfqkbjjbq4d6.narinfo error="server returned 404: 404 page not found\n"12042026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/1/complete12052026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)12062026/10/01 10:03:03 WARN Failed to register uploaded object key=vcz2ihk35rjsdj01q02synd67kcwcvyd.narinfo error="server returned 404: 404 page not found\n"12072026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.02ms)12082026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes12092026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.17ms)12102026/10/01 10:03:03 OK 3_commit_push.sql (639.49µs)12112026/10/01 10:03:03 goose: up to current file version: 312122026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.41ms)12132026/10/01 10:03:03 INFO Upload complete. (68ms)12142026/10/01 10:03:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12152026/10/01 10:03:03 INFO Uploading viaq9ki81jp1qv0i2cdmb5kz9l0xi89r-pinned-file.txt (128B)12162026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)1217=== NAME TestClientPushesUseOnePush1218 client_pushes_test.go:97: Retrieved narinfo from S3:1219 StorePath: /build/TestClientPushesUseOnePush2470362762/001/store/vvk7mj0ll6ml1vw0ddpdzfqkbjjbq4d6-shared-dep1220 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1221 Compression: zstd1222 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821223 NarSize: 1361224 References: 1225 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12262026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures12272026-10-01 10:03:03.688 UTC [675] ERROR: relation "goose_db_version" does not exist at character 3612282026-10-01 10:03:03.688 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12292026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.26ms)12302026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1231 client_pushes_test.go:97: Retrieved narinfo from S3:1232 StorePath: /build/TestClientPushesUseOnePush2470362762/001/store/vcz2ihk35rjsdj01q02synd67kcwcvyd-a1233 URL: nar/149nzhwglqriqjbjs0r6pp5jgxsifw9b6zfajsg719d7bi7w5v17.nar.zst1234 Compression: zstd1235 NarHash: sha256:149nzhwglqriqjbjs0r6pp5jgxsifw9b6zfajsg719d7bi7w5v171236 NarSize: 2161237 References: /build/TestClientPushesUseOnePush2470362762/001/store/vvk7mj0ll6ml1vw0ddpdzfqkbjjbq4d6-shared-dep1238 CA: text:sha256:1gbnai7w5m9wvrmf1n63k0a8baahfh2nlq0p6ypc7vvqkxwd2gvg12392026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12402026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.28ms)12412026/10/01 10:03:03 WARN Failed to register uploaded object key=viaq9ki81jp1qv0i2cdmb5kz9l0xi89r.ls error="server returned 404: 404 page not found\n"12422026/10/01 10:03:03 INFO Signed narinfos id=1 count=112432026/10/01 10:03:03 INFO Uploading 1 narinfos12442026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.31ms)12452026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200001246 client_pushes_test.go:97: Retrieved narinfo from S3:1247 StorePath: /build/TestClientPushesUseOnePush2470362762/001/store/a08db48wjdrp1i9iq163j7m013s8vhc4-b1248 URL: nar/149nzhwglqriqjbjs0r6pp5jgxsifw9b6zfajsg719d7bi7w5v17.nar.zst1249 Compression: zstd1250 NarHash: sha256:149nzhwglqriqjbjs0r6pp5jgxsifw9b6zfajsg719d7bi7w5v171251 NarSize: 2161252 References: /build/TestClientPushesUseOnePush2470362762/001/store/vvk7mj0ll6ml1vw0ddpdzfqkbjjbq4d6-shared-dep1253 CA: text:sha256:1gbnai7w5m9wvrmf1n63k0a8baahfh2nlq0p6ypc7vvqkxwd2gvg1254=== NAME TestClientIntegration1255 client_integration_test.go:286: Created store path: /build/TestClientIntegration657089719/002/store/dhlbfkmnwizmdd2q4j08b5dmm963dkd3-test-file.txt12562026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/1/complete12572026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.24ms)12582026/10/01 10:03:03 WARN Failed to register uploaded object key=viaq9ki81jp1qv0i2cdmb5kz9l0xi89r.narinfo error="server returned 404: 404 page not found\n"12592026/10/01 10:03:03 OK 2_object_stats_trigger.sql (979.87µs)12602026/10/01 10:03:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12612026/10/01 10:03:03 OK 3_commit_push.sql (829.67µs)12622026/10/01 10:03:03 goose: up to current file version: 31263--- PASS: TestClientPushesUseOnePush (0.74s)1264=== CONT TestRegisterCompletedObjectNeedsPendingRow12652026/10/01 10:03:03 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LmJmMGE5YzJkLWU3MjgtNGM0YS04ZjNmLWJmMzg5ZTc1MzE1NXgxNzkwODQ4OTgzNjc1OTA4Nzgy12662026/10/01 10:03:03 INFO Upload complete. (64ms)12672026/10/01 10:03:03 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12682026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures12692026/10/01 10:03:03 OK 20241026095416_initial_model.sql (11.09ms)1270--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.75s)1271=== CONT TestCacheConfigHandler1272=== RUN TestCacheConfigHandler/full_config,_no_issuer12732026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)1274=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1275=== RUN TestCacheConfigHandler/no_cache_url_configured1276=== PAUSE TestCacheConfigHandler/no_cache_url_configured1277=== RUN TestCacheConfigHandler/no_signing_keys1278=== PAUSE TestCacheConfigHandler/no_signing_keys1279=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1280=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1281=== CONT TestSweepSkipsRowsLockedByPush12822026/10/01 10:03:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LmJmMGE5YzJkLWU3MjgtNGM0YS04ZjNmLWJmMzg5ZTc1MzE1NXgxNzkwODQ4OTgzNjc1OTA4Nzgy parts=112832026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.5ms)1284--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.75s)1285=== CONT TestFailedS3DeleteKeepsTombstone12862026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)12872026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures12882026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.93ms)12892026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.83ms)12902026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.25ms)12912026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000012922026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.67ms)12932026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.1ms)12942026/10/01 10:03:03 OK 3_commit_push.sql (1.81ms)12952026/10/01 10:03:03 goose: up to current file version: 312962026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures12972026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes12982026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes12992026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes13002026/10/01 10:03:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13012026/10/01 10:03:03 INFO Uploading j9w5j7psyrn5q8215880ig5zlh9sgkd9-unpinned-file.txt (128B)13022026/10/01 10:03:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13032026/10/01 10:03:03 INFO Uploading dhlbfkmnwizmdd2q4j08b5dmm963dkd3-test-file.txt (152B)13042026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13052026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13062026/10/01 10:03:03 WARN Failed to register uploaded object key=j9w5j7psyrn5q8215880ig5zlh9sgkd9.ls error="server returned 404: 404 page not found\n"13072026/10/01 10:03:03 INFO Signed narinfos id=2 count=113082026/10/01 10:03:03 INFO Uploading 1 narinfos13092026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13102026/10/01 10:03:03 INFO Signed narinfos id=1 count=113112026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1312--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.82s)1313=== CONT TestForceGCDuringPushOffersSweptObject1314=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1315=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1316=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1317=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1318=== CONT TestService_ReadScope_PublicByDefault13192026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/2/complete13202026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13212026/10/01 10:03:03 WARN Failed to register uploaded object key=j9w5j7psyrn5q8215880ig5zlh9sgkd9.narinfo error="server returned 404: 404 page not found\n"13222026/10/01 10:03:03 WARN Failed to register uploaded object key=dhlbfkmnwizmdd2q4j08b5dmm963dkd3.ls error="server returned 404: 404 page not found\n"13232026/10/01 10:03:03 INFO Signed narinfos id=1 count=113242026/10/01 10:03:03 INFO Uploading 1 narinfos13252026-10-01 10:03:03.787 UTC [824] ERROR: relation "goose_db_version" does not exist at character 3613262026-10-01 10:03:03.787 UTC [824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/10/01 10:03:03 INFO Upload complete. (51ms)13282026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13292026/10/01 10:03:03 WARN Failed to register uploaded object key=dhlbfkmnwizmdd2q4j08b5dmm963dkd3.narinfo error="server returned 404: 404 page not found\n"13302026-10-01 10:03:03.794 UTC [828] ERROR: relation "goose_db_version" does not exist at character 3613312026-10-01 10:03:03.794 UTC [828] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13322026-10-01 10:03:03.796 UTC [829] ERROR: relation "goose_db_version" does not exist at character 3613332026-10-01 10:03:03.796 UTC [829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13342026/10/01 10:03:03 INFO Upload complete. (70ms)13352026/10/01 10:03:03 OK 20241026095416_initial_model.sql (13.31ms)13362026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)13372026/10/01 10:03:03 OK 20241026095416_initial_model.sql (11.88ms)13382026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)13392026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.42ms)13402026/10/01 10:03:03 OK 20241026095416_initial_model.sql (10.88ms)13412026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)13422026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.26ms)13432026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)13442026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.45ms)13452026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)13462026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures13472026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.42ms)13482026/10/01 10:03:03 OK 20260905000000_add_claims.sql (2.6ms)13492026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)13502026/10/01 10:03:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures13512026/10/01 10:03:03 INFO Garbage collection started13522026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.94ms)13532026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.17ms)13542026/10/01 10:03:03 INFO Received uploads request method=POST path=/api/pending_closures13552026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.26ms)13562026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.15ms)13572026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000013582026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.63ms)13592026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000013602026/10/01 10:03:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13612026/10/01 10:03:03 INFO Uploading l66lbp9nlqx303pvxb0a5p99xzksvvh6-a (216B)13622026/10/01 10:03:03 INFO Uploading ywqzckncpvqy9vgplvbf23ajx5qzm5d5-shared-dep (136B)13632026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.56ms)1364=== RUN TestPush_RejectsBadRequests/no_objects13652026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.27ms)1366=== PAUSE TestPush_RejectsBadRequests/no_objects1367=== RUN TestPush_RejectsBadRequests/bad_root1368=== PAUSE TestPush_RejectsBadRequests/bad_root1369=== RUN TestPush_RejectsBadRequests/root_not_in_objects1370=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1371=== RUN TestPush_RejectsBadRequests/no_roots1372=== PAUSE TestPush_RejectsBadRequests/no_roots1373=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13742026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.16ms)13752026/10/01 10:03:03 OK 2_object_stats_trigger.sql (2.06ms)13762026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.04ms)13772026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000013782026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.85ms)13792026/10/01 10:03:03 OK 3_commit_push.sql (1.3ms)13802026/10/01 10:03:03 goose: up to current file version: 313812026/10/01 10:03:03 OK 3_commit_push.sql (1.47ms)13822026/10/01 10:03:03 goose: up to current file version: 313832026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13842026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/1qy9av39z63y8jy7p15x1kz1baxxjqa4pdz5kksigzpjxqxabycc.nar.zst error="server returned 404: 404 page not found\n"13852026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.03ms)13862026/10/01 10:03:03 WARN Failed to register uploaded object key=a2r85kpx8jgqk48kifwdhdp1xv9562i5.ls error="server returned 404: 404 page not found\n"13872026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13882026/10/01 10:03:03 INFO Aborted multipart uploads count=0 kept=013892026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.54ms)13902026/10/01 10:03:03 WARN Failed to register uploaded object key=l66lbp9nlqx303pvxb0a5p99xzksvvh6.ls error="server returned 404: 404 page not found\n"13912026/10/01 10:03:03 WARN Failed to register uploaded object key=ywqzckncpvqy9vgplvbf23ajx5qzm5d5.ls error="server returned 404: 404 page not found\n"13922026/10/01 10:03:03 INFO Signed narinfos id=1 count=213932026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13942026/10/01 10:03:03 INFO Signed narinfos id=2 count=213952026/10/01 10:03:03 INFO Uploading 4 narinfos13962026/10/01 10:03:03 INFO All 1 paths already cached13972026/10/01 10:03:03 OK 3_commit_push.sql (1.26ms)13982026/10/01 10:03:03 goose: up to current file version: 31399=== NAME TestClientIntegration1400 client_integration_test.go:312: Retrieved narinfo from S3:1401 StorePath: /build/TestClientIntegration657089719/002/store/dhlbfkmnwizmdd2q4j08b5dmm963dkd3-test-file.txt1402 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1403 Compression: zstd1404 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11405 NarSize: 1521406 References: 1407 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk114082026/10/01 10:03:03 WARN Force mode enabled - objects will be deleted immediately without grace period14092026/10/01 10:03:03 WARN Failed to register uploaded object key=ywqzckncpvqy9vgplvbf23ajx5qzm5d5.narinfo error="server returned 404: 404 page not found\n"14102026/10/01 10:03:03 WARN Failed to register uploaded object key=l66lbp9nlqx303pvxb0a5p99xzksvvh6.narinfo error="server returned 404: 404 page not found\n"14112026/10/01 10:03:03 WARN Failed to register uploaded object key=a2r85kpx8jgqk48kifwdhdp1xv9562i5.narinfo error="server returned 404: 404 page not found\n"1412 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1413 client_integration_test.go:313: Decompressed .ls content (64 bytes):1414 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1415 client_integration_test.go:316: Testing garbage collection...14162026/10/01 10:03:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14172026/10/01 10:03:03 WARN Failed to register uploaded object key=ywqzckncpvqy9vgplvbf23ajx5qzm5d5.narinfo error="server returned 404: 404 page not found\n"14182026/10/01 10:03:03 INFO Completed upload id=11419=== NAME TestClientMultipleUploads1420 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2169546474/001/store/zmzbqdhylvhc67cnsadlf3csq647yq80-test-file-0.txt14212026/10/01 10:03:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14222026/10/01 10:03:03 INFO Completed upload id=214232026/10/01 10:03:03 INFO Upload complete. (72ms)1424=== NAME TestClientFallsBackToClosures1425 client_pushes_test.go:112: Retrieved narinfo from S3:1426 StorePath: /build/TestClientFallsBackToClosures2599723902/001/store/ywqzckncpvqy9vgplvbf23ajx5qzm5d5-shared-dep1427 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1428 Compression: zstd1429 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821430 NarSize: 1361431 References: 1432 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1433 client_pushes_test.go:112: Retrieved narinfo from S3:1434 StorePath: /build/TestClientFallsBackToClosures2599723902/001/store/l66lbp9nlqx303pvxb0a5p99xzksvvh6-a1435 URL: nar/1qy9av39z63y8jy7p15x1kz1baxxjqa4pdz5kksigzpjxqxabycc.nar.zst1436 Compression: zstd1437 NarHash: sha256:1qy9av39z63y8jy7p15x1kz1baxxjqa4pdz5kksigzpjxqxabycc1438 NarSize: 2161439 References: /build/TestClientFallsBackToClosures2599723902/001/store/ywqzckncpvqy9vgplvbf23ajx5qzm5d5-shared-dep1440 CA: text:sha256:1fadjr4b9wc1b81fzgfkinfkch1ixdmsd08f8mqxh1rjpbl4pp7s14412026-10-01 10:03:03.858 UTC [926] ERROR: relation "goose_db_version" does not exist at character 3614422026-10-01 10:03:03.858 UTC [926] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14432026/10/01 10:03:03 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=01444 client_pushes_test.go:112: Retrieved narinfo from S3:1445 StorePath: /build/TestClientFallsBackToClosures2599723902/001/store/a2r85kpx8jgqk48kifwdhdp1xv9562i5-b1446 URL: nar/1qy9av39z63y8jy7p15x1kz1baxxjqa4pdz5kksigzpjxqxabycc.nar.zst1447 Compression: zstd1448 NarHash: sha256:1qy9av39z63y8jy7p15x1kz1baxxjqa4pdz5kksigzpjxqxabycc1449 NarSize: 2161450 References: /build/TestClientFallsBackToClosures2599723902/001/store/ywqzckncpvqy9vgplvbf23ajx5qzm5d5-shared-dep1451 CA: text:sha256:1fadjr4b9wc1b81fzgfkinfkch1ixdmsd08f8mqxh1rjpbl4pp7s14522026/10/01 10:03:03 INFO Vacuumed table table=pending_closures1453--- PASS: TestClientFallsBackToClosures (0.91s)1454=== CONT TestReadRedirectKeepsNarinfoProxied14552026/10/01 10:03:03 INFO Vacuumed table table=pending_objects14562026/10/01 10:03:03 INFO Vacuumed table table=multipart_uploads14572026/10/01 10:03:03 INFO Vacuumed table table=closures14582026/10/01 10:03:03 INFO Vacuumed table table=objects14592026/10/01 10:03:03 OK 20241026095416_initial_model.sql (11.12ms)14602026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes14612026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)14622026/10/01 10:03:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures14632026/10/01 10:03:03 INFO Garbage collection started14642026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.38ms)1465=== NAME TestClientMultipleUploads1466 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2169546474/001/store/4yg1xnn64q3vvb3wfsl84zgrmy576rfg-test-file-1.txt14672026/10/01 10:03:03 INFO Aborted multipart uploads count=0 kept=014682026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (8.37ms)14692026/10/01 10:03:03 WARN Force mode enabled - objects will be deleted immediately without grace period14702026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.09ms)14712026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.26ms)14722026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.36ms)14732026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000014742026/10/01 10:03:03 INFO Aborted multipart uploads count=0 kept=014752026/10/01 10:03:03 OK 1_commit_pending_closure.sql (3.35ms)14762026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14772026/10/01 10:03:03 WARN Force mode enabled - objects will be deleted immediately without grace period14782026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.62ms)14792026/10/01 10:03:03 OK 3_commit_push.sql (1.5ms)14802026/10/01 10:03:03 goose: up to current file version: 314812026/10/01 10:03:03 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=014822026/10/01 10:03:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014832026/10/01 10:03:03 INFO Vacuumed table table=pending_closures14842026/10/01 10:03:03 INFO Vacuumed table table=pending_closures1485--- PASS: TestPush_CompleteCommitsEveryRoot (0.96s)1486=== CONT TestService_RequireScope_OIDC14872026/10/01 10:03:03 INFO Vacuumed table table=pending_objects14882026/10/01 10:03:03 INFO Vacuumed table table=multipart_uploads14892026/10/01 10:03:03 INFO Vacuumed table table=closures14902026/10/01 10:03:03 INFO Vacuumed table table=objects14912026/10/01 10:03:03 INFO Vacuumed table table=pending_objects14922026/10/01 10:03:03 INFO Vacuumed table table=multipart_uploads14932026-10-01 10:03:03.919 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 3614942026-10-01 10:03:03.919 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14952026/10/01 10:03:03 INFO Vacuumed table table=closures1496=== NAME TestClientMultipleUploads1497 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2169546474/001/store/y00n9xpjd844p2vm1d36yxf5m06rpg9v-test-file-2.txt14982026/10/01 10:03:03 INFO Vacuumed table table=objects1499--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.97s)1500=== CONT TestGCSweepDeliversEachKeyOnce15012026-10-01 10:03:03.936 UTC [1024] ERROR: relation "goose_db_version" does not exist at character 3615022026-10-01 10:03:03.936 UTC [1024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15032026/10/01 10:03:03 OK 20241026095416_initial_model.sql (11.36ms)15042026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)15052026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes15062026/10/01 10:03:03 OK 20251218171726_add_pins.sql (4.88ms)15072026/10/01 10:03:03 INFO Aborted multipart uploads count=0 kept=015082026/10/01 10:03:03 WARN Force mode enabled - objects will be deleted immediately without grace period15092026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)15102026/10/01 10:03:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15112026/10/01 10:03:03 INFO Uploading 1ahqm9lidn9p4zdwafv98x8lq0rwqb6m-top (224B)15122026/10/01 10:03:03 INFO Uploading fvnv27cjfh08n99ilwpcwp1hykc19bwk-shared-dep (136B)15132026/10/01 10:03:03 OK 20260905000000_add_claims.sql (4.56ms)15142026/10/01 10:03:03 WARN Failed to register uploaded object key=1ahqm9lidn9p4zdwafv98x8lq0rwqb6m.ls error="server returned 404: 404 page not found\n"15152026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15162026/10/01 10:03:03 OK 20241026095416_initial_model.sql (12.33ms)15172026/10/01 10:03:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15182026/10/01 10:03:03 WARN Failed to register uploaded object key=fvnv27cjfh08n99ilwpcwp1hykc19bwk.ls error="server returned 404: 404 page not found\n"15192026/10/01 10:03:03 WARN Failed to register uploaded object key=nar/1irys38yizsl8ijx3y2zqmz49yxcwllsv8pag3513wi7kcqf51xb.nar.zst error="server returned 404: 404 page not found\n"15202026/10/01 10:03:03 INFO Signed narinfos id=1 count=215212026/10/01 10:03:03 INFO Uploading 2 narinfos15222026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (3.41ms)15232026/10/01 10:03:03 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)15242026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (3.08ms)15252026/10/01 10:03:03 goose: successfully migrated database to version: 2026092312000015262026/10/01 10:03:03 INFO Received complete push request method=POST path=/api/pushes/1/complete15272026/10/01 10:03:03 WARN Failed to register uploaded object key=1ahqm9lidn9p4zdwafv98x8lq0rwqb6m.narinfo error="server returned 404: 404 page not found\n"15282026/10/01 10:03:03 WARN Failed to register uploaded object key=fvnv27cjfh08n99ilwpcwp1hykc19bwk.narinfo error="server returned 404: 404 page not found\n"15292026/10/01 10:03:03 OK 20251218171726_add_pins.sql (3.99ms)15302026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.58ms)15312026/10/01 10:03:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015322026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.69ms)15332026/10/01 10:03:03 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)1534--- PASS: TestGetExistingObjectsLocksRows (0.48s)1535=== CONT TestReadRedirectNar15362026/10/01 10:03:03 OK 3_commit_push.sql (1.9ms)15372026/10/01 10:03:03 INFO Vacuumed table table=pending_closures15382026/10/01 10:03:03 goose: up to current file version: 315392026/10/01 10:03:03 INFO Upload complete. (65ms)15402026/10/01 10:03:03 INFO Vacuumed table table=pending_objects1541=== NAME TestClientSharedPathCommittedMidPush1542 client_integration_test.go:680: Retrieved narinfo from S3:1543 StorePath: /build/TestClientSharedPathCommittedMidPush2883948920/001/store/fvnv27cjfh08n99ilwpcwp1hykc19bwk-shared-dep1544 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1545 Compression: zstd1546 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821547 NarSize: 1361548 References: 1549 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15502026/10/01 10:03:03 OK 20260905000000_add_claims.sql (3.68ms)1551--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.01s)15522026/10/01 10:03:03 INFO Vacuumed table table=multipart_uploads1553=== CONT TestService_AuthMiddleware_OIDC15542026/10/01 10:03:03 INFO Vacuumed table table=closures15552026/10/01 10:03:03 INFO Vacuumed table table=objects15562026/10/01 10:03:03 OK 20260920000000_drop_claims.sql (2.93ms)1557=== NAME TestClientSharedPathCommittedMidPush1558 client_integration_test.go:680: Retrieved narinfo from S3:1559 StorePath: /build/TestClientSharedPathCommittedMidPush2883948920/001/store/1ahqm9lidn9p4zdwafv98x8lq0rwqb6m-top1560 URL: nar/1irys38yizsl8ijx3y2zqmz49yxcwllsv8pag3513wi7kcqf51xb.nar.zst1561 Compression: zstd1562 NarHash: sha256:1irys38yizsl8ijx3y2zqmz49yxcwllsv8pag3513wi7kcqf51xb1563 NarSize: 2241564 References: /build/TestClientSharedPathCommittedMidPush2883948920/001/store/fvnv27cjfh08n99ilwpcwp1hykc19bwk-shared-dep1565 CA: text:sha256:12413lzz98y7dhq6j602wxjha6ibwdsmdkrd97wjzryn5p96y1h61566--- PASS: TestSweepRechecksPendingAfterLocking (0.62s)1567=== CONT TestTombstonedObjectOfferedWithoutWaiting15682026/10/01 10:03:03 OK 20260923120000_add_pushes.sql (2.35ms)15692026/10/01 10:03:03 goose: successfully migrated database to version: 202609231200001570--- PASS: TestClientSharedPathCommittedMidPush (1.02s)1571=== CONT TestReadProxyDisabled15722026/10/01 10:03:03 OK 1_commit_pending_closure.sql (2.58ms)15732026/10/01 10:03:03 OK 2_object_stats_trigger.sql (1.73ms)15742026/10/01 10:03:03 OK 3_commit_push.sql (1.3ms)15752026/10/01 10:03:03 goose: up to current file version: 315762026/10/01 10:03:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15772026-10-01 10:03:03.996 UTC [1109] ERROR: relation "goose_db_version" does not exist at character 3615782026-10-01 10:03:03.996 UTC [1109] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1579=== NAME TestClientWithDependencies1580 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1612190637/001/store/rj06xxvwcxl46r13qlmmqscy7d2hvcid-test-script1581--- PASS: TestReadRedirectUsesPublicS3URL (0.49s)1582=== CONT TestService_ReadAuthMiddleware15832026/10/01 10:03:03 INFO Received push request method=POST path=/api/pushes15842026/10/01 10:03:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15852026/10/01 10:03:04 INFO Uploading zmzbqdhylvhc67cnsadlf3csq647yq80-test-file-0.txt (160B)15862026/10/01 10:03:04 INFO Uploading y00n9xpjd844p2vm1d36yxf5m06rpg9v-test-file-2.txt (160B)15872026/10/01 10:03:04 INFO Uploading 4yg1xnn64q3vvb3wfsl84zgrmy576rfg-test-file-1.txt (160B)15882026/10/01 10:03:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LjVkNDU1ODdiLWIzOTUtNDQyNS1iODA2LTkzM2YwYTZiN2E2NHgxNzkwODQ4OTgzNTkzOTY3NjM0 parts=1215892026/10/01 10:03:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15902026/10/01 10:03:04 WARN Failed to register uploaded object key=zmzbqdhylvhc67cnsadlf3csq647yq80.ls error="server returned 404: 404 page not found\n"15912026/10/01 10:03:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15922026/10/01 10:03:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15932026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures15942026/10/01 10:03:04 WARN Failed to register uploaded object key=y00n9xpjd844p2vm1d36yxf5m06rpg9v.ls error="server returned 404: 404 page not found\n"15952026/10/01 10:03:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15962026/10/01 10:03:04 WARN Failed to register uploaded object key=4yg1xnn64q3vvb3wfsl84zgrmy576rfg.ls error="server returned 404: 404 page not found\n"15972026/10/01 10:03:04 INFO Signed narinfos id=1 count=315982026/10/01 10:03:04 INFO Uploading 3 narinfos15992026/10/01 10:03:04 WARN Failed to register uploaded object key=y00n9xpjd844p2vm1d36yxf5m06rpg9v.narinfo error="server returned 404: 404 page not found\n"16002026/10/01 10:03:04 INFO Received complete push request method=POST path=/api/pushes/1/complete16012026/10/01 10:03:04 WARN Failed to register uploaded object key=4yg1xnn64q3vvb3wfsl84zgrmy576rfg.narinfo error="server returned 404: 404 page not found\n"16022026/10/01 10:03:04 WARN Failed to register uploaded object key=zmzbqdhylvhc67cnsadlf3csq647yq80.narinfo error="server returned 404: 404 page not found\n"16032026/10/01 10:03:04 OK 20241026095416_initial_model.sql (12.59ms)16042026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures16052026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)16062026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.98ms)16072026/10/01 10:03:04 INFO Upload complete. (76ms)1608=== NAME TestClientWithDependencies1609 client_integration_test.go:615: Found 1 dependencies (including self)1610=== NAME TestClientMultipleUploads1611 client_integration_test.go:369: Uploaded 3 paths in 109.585293ms1612--- PASS: TestReadProxyRangeRequest (0.46s)1613=== CONT TestGCSweepSkipsPendingObjects16142026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)16152026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.84ms)1616--- PASS: TestClientMultipleUploads (1.08s)1617=== CONT TestReadProxyRootRedirectsToIndexHTML16182026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.23ms)16192026-10-01 10:03:04.044 UTC [1183] ERROR: relation "goose_db_version" does not exist at character 3616202026-10-01 10:03:04.044 UTC [1183] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16212026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (3.06ms)16222026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000016232026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.45ms)16242026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.28ms)16252026/10/01 10:03:04 OK 3_commit_push.sql (1.51ms)16262026/10/01 10:03:04 goose: up to current file version: 316272026-10-01 10:03:04.057 UTC [1188] ERROR: relation "goose_db_version" does not exist at character 3616282026-10-01 10:03:04.057 UTC [1188] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1629--- PASS: TestCacheStatsHandler (0.45s)1630=== CONT TestDeduplicatedObjectsRecordedAsPending16312026-10-01 10:03:04.063 UTC [1189] ERROR: relation "goose_db_version" does not exist at character 3616322026-10-01 10:03:04.063 UTC [1189] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16332026/10/01 10:03:04 OK 20241026095416_initial_model.sql (14.19ms)16342026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)16352026/10/01 10:03:04 OK 20251218171726_add_pins.sql (8.19ms)16362026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.86ms)1637--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.38s)1638=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16392026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)16402026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)16412026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.93ms)16422026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.67ms)16432026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)16442026-10-01 10:03:04.087 UTC [1227] ERROR: relation "goose_db_version" does not exist at character 3616452026-10-01 10:03:04.087 UTC [1227] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16462026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.68ms)16472026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.52ms)16482026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)16492026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.78ms)16502026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (3.61ms)16512026/10/01 10:03:04 goose: successfully migrated database to version: 202609231200001652=== NAME TestClientCADerivations1653 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations457450659/001/store/srxncl5bj9gr5mcm5wig4yv9q7j85xcz-ca-test16542026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.22ms)16552026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.18ms)16562026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.92ms)16572026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures16582026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.99ms)16592026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000016602026/10/01 10:03:04 OK 2_object_stats_trigger.sql (2.5ms)16612026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)16622026/10/01 10:03:04 OK 3_commit_push.sql (1.83ms)16632026/10/01 10:03:04 goose: up to current file version: 316642026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.43ms)16652026/10/01 10:03:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34803/oidc16662026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.66ms)16672026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.41ms)16682026/10/01 10:03:04 INFO Received push request method=POST path=/api/pushes16692026/10/01 10:03:04 OK 3_commit_push.sql (1.82ms)16702026/10/01 10:03:04 goose: up to current file version: 316712026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.01ms)16722026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.41ms)16732026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)16742026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.75ms)16752026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000016762026/10/01 10:03:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16772026/10/01 10:03:04 INFO Uploading rj06xxvwcxl46r13qlmmqscy7d2hvcid-test-script (136B)16782026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.9ms)16792026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.19ms)16802026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.48ms)16812026/10/01 10:03:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16822026-10-01 10:03:04.115 UTC [1250] ERROR: relation "goose_db_version" does not exist at character 3616832026-10-01 10:03:04.115 UTC [1250] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16842026/10/01 10:03:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16852026/10/01 10:03:04 WARN Failed to register uploaded object key=rj06xxvwcxl46r13qlmmqscy7d2hvcid.ls error="server returned 404: 404 page not found\n"16862026/10/01 10:03:04 WARN Failed to register uploaded object key=log/qypalx0cs6g5vpbyg9lyhkv37z6dbn9g-test-script.drv error="server returned 404: 404 page not found\n"16872026/10/01 10:03:04 INFO Signed narinfos id=1 count=116882026/10/01 10:03:04 INFO Uploading 1 narinfos16892026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)16902026/10/01 10:03:04 OK 3_commit_push.sql (2.41ms)16912026/10/01 10:03:04 goose: up to current file version: 316922026/10/01 10:03:04 INFO Received complete push request method=POST path=/api/pushes/1/complete16932026/10/01 10:03:04 WARN Failed to register uploaded object key=rj06xxvwcxl46r13qlmmqscy7d2hvcid.narinfo error="server returned 404: 404 page not found\n"16942026-10-01 10:03:04.122 UTC [1251] ERROR: relation "goose_db_version" does not exist at character 3616952026-10-01 10:03:04.122 UTC [1251] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16962026/10/01 10:03:04 OK 20260905000000_add_claims.sql (5.28ms)16972026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.47ms)16982026/10/01 10:03:04 INFO Upload complete. (63ms)16992026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.17ms)17002026/10/01 10:03:04 goose: successfully migrated database to version: 202609231200001701 client_ca_test.go:139: Found 1 dependencies (including self)1702=== NAME TestClientWithDependencies1703 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1612190637/001/store) requires matching store prefix17042026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.39ms)17052026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.73ms)1706--- PASS: TestClientWithDependencies (1.17s)1707=== CONT TestPushDedupSurvivesConcurrentGC17082026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.59ms)17092026/10/01 10:03:04 OK 3_commit_push.sql (1.6ms)17102026/10/01 10:03:04 goose: up to current file version: 317112026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (7.17ms)17122026/10/01 10:03:04 OK 20241026095416_initial_model.sql (13.29ms)17132026/10/01 10:03:04 OK 20251218171726_add_pins.sql (2.7ms)17142026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)17152026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.27ms)17162026/10/01 10:03:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17172026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)17182026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=01719--- PASS: TestService_ReadScope_PublicByDefault (0.36s)1720=== CONT TestGCMetrics17212026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period17222026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)17232026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4ms)17242026-10-01 10:03:04.153 UTC [1273] ERROR: relation "goose_db_version" does not exist at character 3617252026-10-01 10:03:04.153 UTC [1273] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17262026/10/01 10:03:04 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=017272026-10-01 10:03:04.154 UTC [1274] ERROR: relation "goose_db_version" does not exist at character 3617282026-10-01 10:03:04.154 UTC [1274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17292026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.82ms)17302026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.33ms)17312026/10/01 10:03:04 INFO Vacuumed table table=pending_closures17322026/10/01 10:03:04 INFO Vacuumed table table=pending_objects17332026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads17342026/10/01 10:03:04 INFO Vacuumed table table=closures17352026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.65ms)17362026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.34ms)17372026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000017382026/10/01 10:03:04 INFO Vacuumed table table=objects17392026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.45ms)17402026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000017412026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.14ms)17422026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.62ms)17432026/10/01 10:03:04 OK 2_object_stats_trigger.sql (2.51ms)17442026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=017452026/10/01 10:03:04 OK 3_commit_push.sql (2.71ms)17462026/10/01 10:03:04 goose: up to current file version: 317472026/10/01 10:03:04 OK 2_object_stats_trigger.sql (3.57ms)17482026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period17492026/10/01 10:03:04 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LmUyNGY1M2U4LTdjNjEtNGEwOC1hNDZiLWM1MjA1MGRiMTI0MHgxNzkwODQ4OTgzNzQ3MjA1Nzk0 parts=1217502026/10/01 10:03:04 OK 3_commit_push.sql (1.84ms)17512026/10/01 10:03:04 goose: up to current file version: 317522026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures17532026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.41ms)17542026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)1755--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.21s)1756=== CONT TestGCBugBareHashReferences17572026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.34ms)17582026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)17592026/10/01 10:03:04 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=017602026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.12ms)17612026/10/01 10:03:04 INFO Vacuumed table table=pending_closures17622026/10/01 10:03:04 INFO Vacuumed table table=pending_objects17632026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads17642026/10/01 10:03:04 INFO Vacuumed table table=closures17652026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=017662026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)17672026/10/01 10:03:04 OK 20251218171726_add_pins.sql (5.1ms)17682026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures17692026/10/01 10:03:04 INFO Vacuumed table table=objects17702026-10-01 10:03:04.182 UTC [1297] ERROR: relation "goose_db_version" does not exist at character 3617712026-10-01 10:03:04.182 UTC [1297] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1772--- PASS: TestSweepSkipsRowsLockedByPush (0.48s)1773=== CONT TestService_AuthMiddleware_MTLSProxyHeader17742026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period17752026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.35ms)17762026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)17772026/10/01 10:03:04 OK 20260905000000_add_claims.sql (2.87ms)17782026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.07ms)17792026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.36ms)17802026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.53ms)17812026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000017822026/10/01 10:03:04 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17832026/10/01 10:03:04 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."17842026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.97ms)17852026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (3.28ms)17862026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000017872026/10/01 10:03:04 OK 2_object_stats_trigger.sql (2.29ms)1788--- PASS: TestFailedS3DeleteKeepsTombstone (0.48s)1789=== CONT TestLeadEndsOnShutdown17902026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.03ms)17912026/10/01 10:03:04 OK 3_commit_push.sql (1.58ms)17922026/10/01 10:03:04 goose: up to current file version: 317932026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.49ms)17942026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.46ms)17952026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)17962026/10/01 10:03:04 OK 3_commit_push.sql (1.7ms)17972026/10/01 10:03:04 goose: up to current file version: 317982026/10/01 10:03:04 OK 20251218171726_add_pins.sql (5ms)17992026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)1800--- PASS: TestReadRedirectKeepsNarinfoProxied (0.35s)1801=== CONT TestReadProxyConditionalGet18022026-10-01 10:03:04.214 UTC [1321] ERROR: relation "goose_db_version" does not exist at character 3618032026-10-01 10:03:04.214 UTC [1321] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18042026/10/01 10:03:04 OK 20260905000000_add_claims.sql (9.95ms)18052026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.23ms)1806--- PASS: TestPushWaitsForSweepHoldingRow (1.26s)1807=== CONT TestLeadElectsOneAndHandsOver18082026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.89ms)18092026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000018102026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.44ms)18112026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.54ms)18122026-10-01 10:03:04.231 UTC [1325] ERROR: relation "goose_db_version" does not exist at character 3618132026-10-01 10:03:04.231 UTC [1325] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18142026/10/01 10:03:04 OK 3_commit_push.sql (2.27ms)18152026/10/01 10:03:04 goose: up to current file version: 318162026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.66ms)18172026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)18182026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.64ms)18192026/10/01 10:03:04 INFO Received push request method=POST path=/api/pushes18202026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)18212026/10/01 10:03:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18222026/10/01 10:03:04 INFO Uploading srxncl5bj9gr5mcm5wig4yv9q7j85xcz-ca-test (144B)18232026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.7ms)18242026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.49ms)18252026/10/01 10:03:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18262026-10-01 10:03:04.250 UTC [1344] ERROR: relation "goose_db_version" does not exist at character 3618272026-10-01 10:03:04.250 UTC [1344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18282026/10/01 10:03:04 WARN Failed to register uploaded object key=srxncl5bj9gr5mcm5wig4yv9q7j85xcz.ls error="server returned 404: 404 page not found\n"18292026/10/01 10:03:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18302026/10/01 10:03:04 WARN Failed to register uploaded object key=log/9s3npq3krbz7d6w1r31qcckybrxczi9n-ca-test.drv error="server returned 404: 404 page not found\n"18312026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.58ms)18322026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)18332026/10/01 10:03:04 INFO Signed narinfos id=1 count=118342026/10/01 10:03:04 INFO Uploading 1 narinfos18352026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.42ms)18362026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000018372026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.41ms)18382026/10/01 10:03:04 INFO Received complete push request method=POST path=/api/pushes/1/complete18392026/10/01 10:03:04 WARN Failed to register uploaded object key=srxncl5bj9gr5mcm5wig4yv9q7j85xcz.narinfo error="server returned 404: 404 page not found\n"18402026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=018412026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.68ms)18422026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.92ms)18432026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)18442026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period18452026/10/01 10:03:04 OK 3_commit_push.sql (1.28ms)18462026/10/01 10:03:04 goose: up to current file version: 31847--- PASS: TestReadRedirectNar (0.29s)1848=== CONT TestOrphanedObjectsGCStressTest18492026/10/01 10:03:04 INFO Upload complete. (96ms)18502026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.72ms)18512026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.65ms)1852=== NAME TestClientCADerivations1853 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations457450659/001/store/srxncl5bj9gr5mcm5wig4yv9q7j85xcz-ca-test1854 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1855 Compression: zstd1856 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1857 NarSize: 1441858 References: 1859 Deriver: /build/TestClientCADerivations457450659/001/store/9s3npq3krbz7d6w1r31qcckybrxczi9n-ca-test.drv1860 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1861 client_ca_test.go:185: Checking for realisation files in S3...18622026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.23ms)1863 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1864 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18652026-10-01 10:03:04.267 UTC [1347] ERROR: relation "goose_db_version" does not exist at character 3618662026-10-01 10:03:04.267 UTC [1347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18672026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.42ms)18682026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000018692026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)18702026/10/01 10:03:04 OK 1_commit_pending_closure.sql (8.34ms)18712026/10/01 10:03:04 OK 20251218171726_add_pins.sql (7.47ms)18722026/10/01 10:03:04 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=018732026/10/01 10:03:04 INFO Vacuumed table table=pending_closures18742026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.89ms)18752026/10/01 10:03:04 INFO Vacuumed table table=pending_objects18762026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures18772026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads18782026/10/01 10:03:04 OK 3_commit_push.sql (1.57ms)18792026/10/01 10:03:04 goose: up to current file version: 318802026/10/01 10:03:04 INFO Vacuumed table table=closures18812026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)18822026/10/01 10:03:04 INFO Vacuumed table table=objects18832026/10/01 10:03:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40479/oidc1884--- PASS: TestGCSweepDeliversEachKeyOnce (0.36s)1885=== CONT TestReadProxyHead18862026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.65ms)1887--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.31s)1888=== CONT TestOrphanedObjectsGC18892026/10/01 10:03:04 OK 20241026095416_initial_model.sql (8.91ms)18902026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (1.9ms)18912026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)18922026-10-01 10:03:04.287 UTC [1350] ERROR: relation "goose_db_version" does not exist at character 3618932026-10-01 10:03:04.287 UTC [1350] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18942026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.04ms)18952026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000018962026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.99ms)18972026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.37ms)18982026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.92ms)18992026/10/01 10:03:04 OK 3_commit_push.sql (1.49ms)19002026/10/01 10:03:04 goose: up to current file version: 319012026-10-01 10:03:04.295 UTC [1356] ERROR: relation "goose_db_version" does not exist at character 3619022026-10-01 10:03:04.295 UTC [1356] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19032026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)19042026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.06ms)1905--- PASS: TestReadProxyDisabled (0.32s)1906=== CONT TestService_createPendingClosureHandler19072026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.29ms)19082026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.17ms)19092026-10-01 10:03:04.304 UTC [1358] ERROR: relation "goose_db_version" does not exist at character 3619102026-10-01 10:03:04.304 UTC [1358] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19112026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.16ms)19122026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000019132026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)19142026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.59ms)19152026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.9ms)19162026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.36ms)19172026/10/01 10:03:04 OK 3_commit_push.sql (1.45ms)19182026/10/01 10:03:04 goose: up to current file version: 319192026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)19202026/10/01 10:03:04 OK 20241026095416_initial_model.sql (13.83ms)19212026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)19222026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.11ms)19232026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.9ms)19242026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.27ms)19252026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.49ms)19262026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)1927--- PASS: TestService_ReadAuthMiddleware (0.33s)1928=== CONT TestObjectStatsTrigger19292026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.66ms)19302026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000019312026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.73ms)19322026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.09ms)19332026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)19342026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.64ms)19352026/10/01 10:03:04 OK 3_commit_push.sql (2.6ms)19362026/10/01 10:03:04 goose: up to current file version: 319372026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)19382026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.35ms)19392026/10/01 10:03:04 OK 20260905000000_add_claims.sql (10.21ms)19402026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (11.15ms)19412026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.71ms)19422026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.9ms)19432026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000019442026-10-01 10:03:04.346 UTC [1381] ERROR: relation "goose_db_version" does not exist at character 3619452026-10-01 10:03:04.346 UTC [1381] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19462026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.23ms)19472026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (4.7ms)19482026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000019492026/10/01 10:03:04 OK 2_object_stats_trigger.sql (2.38ms)19502026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures19512026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.93ms)19522026/10/01 10:03:04 OK 3_commit_push.sql (1.67ms)19532026/10/01 10:03:04 goose: up to current file version: 319542026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.71ms)19552026/10/01 10:03:04 OK 3_commit_push.sql (2.19ms)19562026/10/01 10:03:04 goose: up to current file version: 31957=== NAME TestClientCADerivations1958 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1959 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1960 error: binary cache 's3://bucket30?endpoint=http://localhost:46651&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations457450659/001/store'1961 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11962--- PASS: TestClientCADerivations (0.81s)1963=== CONT TestReadProxyInvalidPath19642026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.68ms)19652026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)19662026-10-01 10:03:04.370 UTC [1479] ERROR: relation "goose_db_version" does not exist at character 3619672026-10-01 10:03:04.370 UTC [1479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19682026-10-01 10:03:04.370 UTC [1480] ERROR: relation "goose_db_version" does not exist at character 3619692026-10-01 10:03:04.370 UTC [1480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19702026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.61ms)19712026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=019722026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)19732026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period19742026-10-01 10:03:04.380 UTC [1484] ERROR: relation "goose_db_version" does not exist at character 3619752026-10-01 10:03:04.380 UTC [1484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19762026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.01ms)19772026-10-01 10:03:04.381 UTC [1485] ERROR: relation "goose_db_version" does not exist at character 3619782026-10-01 10:03:04.381 UTC [1485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1979--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.34s)1980=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT19812026/10/01 10:03:04 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=019822026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (9.11ms)1983--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.56s)19842026/10/01 10:03:04 OK 20241026095416_initial_model.sql (13.14ms)1985=== CONT TestPendingCleanupUsesOneCutoff19862026/10/01 10:03:04 OK 20241026095416_initial_model.sql (13.25ms)19872026/10/01 10:03:04 INFO Vacuumed table table=pending_closures19882026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.46ms)19892026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000019902026/10/01 10:03:04 INFO Vacuumed table table=pending_objects19912026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)19922026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)19932026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads19942026/10/01 10:03:04 INFO Vacuumed table table=closures19952026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.48ms)19962026/10/01 10:03:04 INFO Vacuumed table table=objects19972026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.44ms)19982026/10/01 10:03:04 OK 2_object_stats_trigger.sql (2.07ms)19992026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.39ms)20002026/10/01 10:03:04 OK 3_commit_push.sql (1.58ms)20012026/10/01 10:03:04 goose: up to current file version: 320022026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)20032026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (9.76ms)20042026/10/01 10:03:04 OK 20260905000000_add_claims.sql (7.99ms)20052026/10/01 10:03:04 OK 20241026095416_initial_model.sql (17.79ms)20062026/10/01 10:03:04 OK 20241026095416_initial_model.sql (18.13ms)2007--- PASS: TestGCSweepSkipsPendingObjects (0.38s)2008=== CONT TestReadProxy40420092026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.67ms)20102026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.85ms)20112026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)20122026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures20132026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (4.55ms)20142026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.08ms)20152026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.76ms)20162026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.65ms)20172026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000020182026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.34ms)20192026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.36ms)20202026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (3.28ms)20212026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000020222026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)20232026-10-01 10:03:04.420 UTC [1491] ERROR: relation "goose_db_version" does not exist at character 3620242026-10-01 10:03:04.420 UTC [1491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20252026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.6ms)20262026/10/01 10:03:04 OK 3_commit_push.sql (1.07ms)20272026/10/01 10:03:04 goose: up to current file version: 320282026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)20292026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.83ms)2030--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.36s)2031=== CONT TestCompleteMultipartUnregistered20322026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.63ms)20332026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.61ms)20342026/10/01 10:03:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20352026/10/01 10:03:04 OK 3_commit_push.sql (1.64ms)20362026/10/01 10:03:04 goose: up to current file version: 320372026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.24ms)20382026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.01ms)20392026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.47ms)20402026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.74ms)20412026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000020422026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.55ms)20432026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000020442026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.04ms)20452026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.79ms)20462026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.38ms)20472026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.48ms)20482026/10/01 10:03:04 OK 3_commit_push.sql (1.35ms)20492026/10/01 10:03:04 goose: up to current file version: 320502026/10/01 10:03:04 OK 3_commit_push.sql (1.27ms)20512026/10/01 10:03:04 goose: up to current file version: 320522026/10/01 10:03:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20532026/10/01 10:03:04 WARN mTLS auth: bound subjects configured but subject DN unavailable20542026/10/01 10:03:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2055--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.36s)2056=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded20572026/10/01 10:03:04 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LmFkYjZlNjYzLWJjN2EtNGEzMC05ZDkzLTczZjYxZWI4YWIyZngxNzkwODQ4OTg0MDI4NTY0MzMy error="Get \"http://127.0.0.1:1/bucket12/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20582026/10/01 10:03:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LjM5N2Y3YTRiLTJiZGUtNGMwNS1iNjE4LWIxMjJjZWZmNzVmMHgxNzkwODQ4OTg0MDIxMDY5NjQ1 parts=1220592026/10/01 10:03:04 OK 20241026095416_initial_model.sql (12.63ms)20602026/10/01 10:03:04 INFO Received cleanup request method=DELETE path=/api/pending_closures20612026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)20622026/10/01 10:03:04 INFO Aborted multipart uploads count=1 kept=020632026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.19ms)2064--- PASS: TestRedundantMultipartUpload (1.49s)2065=== CONT TestReadProxyNarStreaming20662026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)20672026-10-01 10:03:04.453 UTC [1497] ERROR: relation "goose_db_version" does not exist at character 3620682026-10-01 10:03:04.453 UTC [1497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20692026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.39ms)20702026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3ms)2071=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2072=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2073=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2074=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2075=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2076=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2077=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2078=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2079=== CONT TestService_verifyS3Integrity20802026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (8.37ms)20812026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000020822026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.78ms)20832026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.69ms)20842026-10-01 10:03:04.472 UTC [1501] ERROR: relation "goose_db_version" does not exist at character 3620852026-10-01 10:03:04.472 UTC [1501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20862026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)20872026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.5ms)20882026/10/01 10:03:04 OK 3_commit_push.sql (1.21ms)20892026/10/01 10:03:04 goose: up to current file version: 320902026/10/01 10:03:04 OK 20251218171726_add_pins.sql (2.97ms)20912026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)20922026-10-01 10:03:04.482 UTC [1503] ERROR: relation "goose_db_version" does not exist at character 3620932026-10-01 10:03:04.482 UTC [1503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20942026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.39ms)20952026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.6ms)20962026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.23ms)20972026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000020982026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.57ms)20992026/10/01 10:03:04 OK 20241026095416_initial_model.sql (12.52ms)21002026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.87ms)21012026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)21022026/10/01 10:03:04 OK 3_commit_push.sql (1.57ms)21032026/10/01 10:03:04 goose: up to current file version: 321042026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.84ms)21052026-10-01 10:03:04.499 UTC [1504] ERROR: relation "goose_db_version" does not exist at character 3621062026-10-01 10:03:04.499 UTC [1504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21072026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.87ms)21082026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)21092026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)21102026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures21112026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.83ms)21122026-10-01 10:03:04.506 UTC [1505] ERROR: relation "goose_db_version" does not exist at character 3621132026-10-01 10:03:04.506 UTC [1505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21142026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.63ms)21152026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.66ms)21162026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)21172026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.81ms)21182026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000021192026-10-01 10:03:04.513 UTC [1506] ERROR: relation "goose_db_version" does not exist at character 3621202026-10-01 10:03:04.513 UTC [1506] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21212026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.39ms)21222026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4ms)21232026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.67ms)21242026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=021252026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.13ms)21262026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period21272026/10/01 10:03:04 OK 3_commit_push.sql (8.68ms)21282026/10/01 10:03:04 goose: up to current file version: 321292026/10/01 10:03:04 OK 20241026095416_initial_model.sql (19.68ms)21302026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (7.31ms)21312026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000021322026/10/01 10:03:04 OK 20241026095416_initial_model.sql (13.46ms)21332026/10/01 10:03:04 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=021342026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)21352026/10/01 10:03:04 INFO Vacuumed table table=pending_closures21362026/10/01 10:03:04 INFO Vacuumed table table=pending_objects21372026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)21382026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads21392026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.01ms)21402026/10/01 10:03:04 INFO Vacuumed table table=closures21412026/10/01 10:03:04 INFO Vacuumed table table=objects21422026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.57ms)21432026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.85ms)21442026/10/01 10:03:04 OK 3_commit_push.sql (1.45ms)21452026/10/01 10:03:04 goose: up to current file version: 321462026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.22ms)2147--- PASS: TestGCMetrics (0.39s)2148=== CONT TestMultipartCleanup21492026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)21502026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)21512026-10-01 10:03:04.538 UTC [1508] ERROR: relation "goose_db_version" does not exist at character 3621522026-10-01 10:03:04.538 UTC [1508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21532026/10/01 10:03:04 OK 20241026095416_initial_model.sql (12.79ms)21542026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.31ms)21552026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.71ms)21562026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)21572026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.02ms)21582026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.22ms)21592026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (1.36ms)21602026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000021612026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (1.54ms)21622026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000021632026-10-01 10:03:04.545 UTC [1511] ERROR: relation "goose_db_version" does not exist at character 3621642026-10-01 10:03:04.545 UTC [1511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21652026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.07ms)21662026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.67ms)21672026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.31ms)21682026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.23ms)21692026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.91ms)21702026/10/01 10:03:04 OK 3_commit_push.sql (1.5ms)21712026/10/01 10:03:04 goose: up to current file version: 321722026/10/01 10:03:04 OK 3_commit_push.sql (1.72ms)21732026/10/01 10:03:04 goose: up to current file version: 321742026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)21752026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.54ms)2176--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.37s)2177=== CONT TestReadProxyNarinfoAlreadyDecompressed21782026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.88ms)21792026/10/01 10:03:04 OK 20241026095416_initial_model.sql (12.25ms)21802026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)21812026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.61ms)21822026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000021832026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.01ms)21842026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.89ms)21852026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.65ms)21862026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)21872026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.66ms)21882026/10/01 10:03:04 OK 3_commit_push.sql (1.48ms)21892026/10/01 10:03:04 goose: up to current file version: 321902026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)21912026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.65ms)21922026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.13ms)21932026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)21942026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.94ms)21952026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.89ms)21962026/10/01 10:03:04 INFO lead: acquired remote=192.0.2.1:123421972026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=021982026/10/01 10:03:04 INFO lead: released remote=192.0.2.1:12342199--- PASS: TestLeadEndsOnShutdown (0.38s)2200=== CONT TestReadProxyNarinfo22012026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.68ms)22022026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000022032026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.72ms)22042026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.41ms)22052026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.36ms)22062026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.28ms)22072026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000022082026/10/01 10:03:04 OK 3_commit_push.sql (1.72ms)22092026/10/01 10:03:04 goose: up to current file version: 322102026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.25ms)22112026/10/01 10:03:04 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=022122026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.52ms)22132026/10/01 10:03:04 OK 3_commit_push.sql (1.46ms)22142026/10/01 10:03:04 goose: up to current file version: 322152026/10/01 10:03:04 INFO Vacuumed table table=pending_closures22162026/10/01 10:03:04 INFO Vacuumed table table=pending_objects22172026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads22182026/10/01 10:03:04 INFO Vacuumed table table=closures22192026/10/01 10:03:04 INFO Vacuumed table table=objects22202026/10/01 10:03:04 INFO Aborted multipart uploads count=0 kept=022212026/10/01 10:03:04 WARN Force mode enabled - objects will be deleted immediately without grace period22222026/10/01 10:03:04 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=022232026/10/01 10:03:04 INFO Vacuumed table table=pending_closures22242026-10-01 10:03:04.603 UTC [1517] ERROR: relation "goose_db_version" does not exist at character 3622252026-10-01 10:03:04.603 UTC [1517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22262026/10/01 10:03:04 INFO Vacuumed table table=pending_objects2227--- PASS: TestReadProxyConditionalGet (0.39s)2228=== CONT TestNARDeduplicationMetadataUploadBug22292026/10/01 10:03:04 INFO Vacuumed table table=multipart_uploads22302026/10/01 10:03:04 INFO Vacuumed table table=closures22312026/10/01 10:03:04 INFO Vacuumed table table=objects2232--- PASS: TestPushDedupSurvivesConcurrentGC (0.48s)2233=== CONT TestIsValidCachePath2234=== RUN TestIsValidCachePath/narinfo2235=== PAUSE TestIsValidCachePath/narinfo2236=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2237=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2238=== RUN TestIsValidCachePath/nar_zst2239=== PAUSE TestIsValidCachePath/nar_zst2240=== RUN TestIsValidCachePath/nar_xz2241=== PAUSE TestIsValidCachePath/nar_xz2242=== RUN TestIsValidCachePath/nar_bz22243=== PAUSE TestIsValidCachePath/nar_bz22244=== RUN TestIsValidCachePath/nar_uncompressed2245=== PAUSE TestIsValidCachePath/nar_uncompressed2246=== RUN TestIsValidCachePath/ls2247=== PAUSE TestIsValidCachePath/ls2248=== RUN TestIsValidCachePath/log2249=== PAUSE TestIsValidCachePath/log2250=== RUN TestIsValidCachePath/realisation2251=== PAUSE TestIsValidCachePath/realisation2252=== RUN TestIsValidCachePath/nix-cache-info2253=== PAUSE TestIsValidCachePath/nix-cache-info2254=== RUN TestIsValidCachePath/index.html2255=== PAUSE TestIsValidCachePath/index.html2256=== RUN TestIsValidCachePath/traversal_parent2257=== PAUSE TestIsValidCachePath/traversal_parent2258=== RUN TestIsValidCachePath/traversal_in_middle2259=== PAUSE TestIsValidCachePath/traversal_in_middle2260=== RUN TestIsValidCachePath/invalid_char_e2261=== PAUSE TestIsValidCachePath/invalid_char_e2262=== RUN TestIsValidCachePath/invalid_char_u2263=== PAUSE TestIsValidCachePath/invalid_char_u2264=== RUN TestIsValidCachePath/random_path2265=== PAUSE TestIsValidCachePath/random_path2266=== RUN TestIsValidCachePath/empty2267=== PAUSE TestIsValidCachePath/empty2268=== RUN TestIsValidCachePath/leading_slash2269=== PAUSE TestIsValidCachePath/leading_slash2270=== RUN TestIsValidCachePath/wrong_extension2271=== PAUSE TestIsValidCachePath/wrong_extension2272=== RUN TestIsValidCachePath/short_hash2273=== PAUSE TestIsValidCachePath/short_hash2274=== CONT TestServerTLSConfig2275=== RUN TestServerTLSConfig/no_client_CA2276=== PAUSE TestServerTLSConfig/no_client_CA2277=== RUN TestServerTLSConfig/missing_CA_file2278=== PAUSE TestServerTLSConfig/missing_CA_file2279=== RUN TestServerTLSConfig/not_a_PEM_file2280=== PAUSE TestServerTLSConfig/not_a_PEM_file2281=== CONT TestProxyHeadersOnlyTrustedOnSocket22822026/10/01 10:03:04 OK 20241026095416_initial_model.sql (9.67ms)22832026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)22842026/10/01 10:03:04 INFO lead: acquired remote=192.0.2.1:123422852026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.97ms)22862026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)22872026-10-01 10:03:04.632 UTC [1523] ERROR: relation "goose_db_version" does not exist at character 3622882026-10-01 10:03:04.632 UTC [1523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22892026/10/01 10:03:04 OK 20260905000000_add_claims.sql (9.02ms)22902026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.5ms)22912026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.42ms)22922026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000022932026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.38ms)22942026/10/01 10:03:04 OK 2_object_stats_trigger.sql (2.17ms)22952026/10/01 10:03:04 OK 3_commit_push.sql (1.11ms)22962026/10/01 10:03:04 goose: up to current file version: 322972026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.26ms)22982026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)22992026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.41ms)23002026-10-01 10:03:04.657 UTC [1524] ERROR: relation "goose_db_version" does not exist at character 3623012026-10-01 10:03:04.657 UTC [1524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23022026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)23032026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.42ms)23042026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.24ms)23052026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.42ms)23062026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000023072026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.23ms)23082026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.48ms)23092026/10/01 10:03:04 OK 3_commit_push.sql (1.18ms)23102026/10/01 10:03:04 goose: up to current file version: 323112026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.17ms)23122026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)23132026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.37ms)23142026-10-01 10:03:04.682 UTC [1525] ERROR: relation "goose_db_version" does not exist at character 3623152026-10-01 10:03:04.682 UTC [1525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23162026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)23172026/10/01 10:03:04 OK 20260905000000_add_claims.sql (2.9ms)23182026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.12ms)23192026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (1.89ms)23202026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000023212026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.35ms)2322--- PASS: TestReadProxyHead (0.41s)2323=== CONT TestService_NativeMTLS23242026-10-01 10:03:04.694 UTC [1526] ERROR: relation "goose_db_version" does not exist at character 3623252026-10-01 10:03:04.694 UTC [1526] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23262026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.58ms)23272026/10/01 10:03:04 OK 3_commit_push.sql (826.95µs)23282026/10/01 10:03:04 goose: up to current file version: 323292026/10/01 10:03:04 OK 20241026095416_initial_model.sql (9.23ms)23302026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)23312026/10/01 10:03:04 OK 20251218171726_add_pins.sql (2.63ms)23322026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)23332026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures23342026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures23352026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures23362026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.43ms)23372026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (1.96ms)23382026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.32ms)23392026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)23402026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (3.09ms)23412026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000023422026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.59ms)23432026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.07ms)23442026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.56ms)23452026/10/01 10:03:04 OK 3_commit_push.sql (1.37ms)23462026/10/01 10:03:04 goose: up to current file version: 323472026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)23482026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.66ms)23492026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.62ms)23502026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.59ms)23512026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000023522026/10/01 10:03:04 OK 1_commit_pending_closure.sql (3.12ms)23532026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.44ms)23542026/10/01 10:03:04 OK 3_commit_push.sql (1.26ms)23552026/10/01 10:03:04 goose: up to current file version: 32356=== RUN TestService_RequireScope_OIDC/builder_may_write2357=== PAUSE TestService_RequireScope_OIDC/builder_may_write2358=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2359=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2360=== RUN TestService_RequireScope_OIDC/ops_may_admin2361=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2362=== RUN TestService_RequireScope_OIDC/ops_may_not_write2363=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2364=== RUN TestService_RequireScope_OIDC/reader_may_not_write2365=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2366=== RUN TestService_RequireScope_OIDC/static_token_may_admin2367=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2368=== RUN TestService_RequireScope_OIDC/static_token_may_write2369=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2370=== RUN TestService_RequireScope_OIDC/reader_may_read2371=== PAUSE TestService_RequireScope_OIDC/reader_may_read2372=== RUN TestService_RequireScope_OIDC/writer_implies_read2373=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2374=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2375=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2376=== CONT TestParseSingleRange2377=== RUN TestParseSingleRange/none2378=== PAUSE TestParseSingleRange/none2379=== RUN TestParseSingleRange/unknown_unit2380=== PAUSE TestParseSingleRange/unknown_unit2381=== RUN TestParseSingleRange/multi-range_ignored2382=== PAUSE TestParseSingleRange/multi-range_ignored2383=== RUN TestParseSingleRange/malformed_no_dash2384=== PAUSE TestParseSingleRange/malformed_no_dash2385=== RUN TestParseSingleRange/malformed_both_empty2386=== PAUSE TestParseSingleRange/malformed_both_empty2387=== RUN TestParseSingleRange/malformed_end_before_start2388=== PAUSE TestParseSingleRange/malformed_end_before_start2389=== RUN TestParseSingleRange/closed2390=== PAUSE TestParseSingleRange/closed2391=== RUN TestParseSingleRange/open-ended2392=== PAUSE TestParseSingleRange/open-ended2393=== RUN TestParseSingleRange/end_clamped_to_size2394=== PAUSE TestParseSingleRange/end_clamped_to_size2395=== RUN TestParseSingleRange/suffix2396=== PAUSE TestParseSingleRange/suffix2397=== RUN TestParseSingleRange/suffix_exceeds_size2398=== PAUSE TestParseSingleRange/suffix_exceeds_size2399=== RUN TestParseSingleRange/single_byte2400=== PAUSE TestParseSingleRange/single_byte2401=== RUN TestParseSingleRange/start_past_EOF2402=== PAUSE TestParseSingleRange/start_past_EOF2403=== RUN TestParseSingleRange/start_far_past_EOF2404=== PAUSE TestParseSingleRange/start_far_past_EOF2405=== CONT TestMetricsInventory2406--- PASS: TestGCBugBareHashReferences (0.58s)2407=== CONT TestPresentNotReportedWhileGCDeletesClosure24082026-10-01 10:03:04.768 UTC [1533] ERROR: relation "goose_db_version" does not exist at character 3624092026-10-01 10:03:04.768 UTC [1533] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2410--- PASS: TestObjectStatsTrigger (0.45s)2411=== CONT TestPresentReportsOnlyClosureRoots24122026/10/01 10:03:04 INFO lead: released remote=192.0.2.1:12342413--- PASS: TestReadProxyInvalidPath (0.41s)2414=== CONT TestCreatePin_ReservedPins24152026/10/01 10:03:04 OK 20241026095416_initial_model.sql (18.81ms)24162026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)24172026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures24182026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.83ms)24192026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)24202026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.8ms)2421--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.43s)2422=== CONT TestUploadHandlersRejectInvalidKeys24232026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (3.02ms)2424=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2425=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2426=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2427=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2428=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2429=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2430=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2431=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2432=== CONT TestIsValidUploadKey2433=== RUN TestIsValidUploadKey/narinfo2434=== PAUSE TestIsValidUploadKey/narinfo2435=== RUN TestIsValidUploadKey/nar_zst2436=== PAUSE TestIsValidUploadKey/nar_zst2437=== RUN TestIsValidUploadKey/nar_xz2438=== PAUSE TestIsValidUploadKey/nar_xz2439=== RUN TestIsValidUploadKey/nar_plain2440=== PAUSE TestIsValidUploadKey/nar_plain2441=== RUN TestIsValidUploadKey/listing2442=== PAUSE TestIsValidUploadKey/listing2443=== RUN TestIsValidUploadKey/build_log2444=== PAUSE TestIsValidUploadKey/build_log2445=== RUN TestIsValidUploadKey/build_log_home-manager_file2446=== PAUSE TestIsValidUploadKey/build_log_home-manager_file2447=== RUN TestIsValidUploadKey/build_log_plus_in_name2448=== PAUSE TestIsValidUploadKey/build_log_plus_in_name2449=== RUN TestIsValidUploadKey/build_log_question_mark2450=== PAUSE TestIsValidUploadKey/build_log_question_mark2451=== RUN TestIsValidUploadKey/build_log_equals2452=== PAUSE TestIsValidUploadKey/build_log_equals2453=== RUN TestIsValidUploadKey/realisation2454=== PAUSE TestIsValidUploadKey/realisation2455=== RUN TestIsValidUploadKey/realisation_plus_in_output2456=== PAUSE TestIsValidUploadKey/realisation_plus_in_output2457=== RUN TestIsValidUploadKey/nix-cache-info2458=== PAUSE TestIsValidUploadKey/nix-cache-info2459=== RUN TestIsValidUploadKey/index.html2460=== PAUSE TestIsValidUploadKey/index.html2461=== RUN TestIsValidUploadKey/narinfo_key,_nar_type2462=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type2463=== RUN TestIsValidUploadKey/nar_key,_narinfo_type2464=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type2465=== RUN TestIsValidUploadKey/listing_key,_narinfo_type2466=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type2467=== RUN TestIsValidUploadKey/traversal2468=== PAUSE TestIsValidUploadKey/traversal2469=== RUN TestIsValidUploadKey/traversal_nar2470=== PAUSE TestIsValidUploadKey/traversal_nar2471=== RUN TestIsValidUploadKey/absolute2472=== PAUSE TestIsValidUploadKey/absolute2473=== RUN TestIsValidUploadKey/empty_key2474=== PAUSE TestIsValidUploadKey/empty_key2475=== RUN TestIsValidUploadKey/unknown_type2476=== PAUSE TestIsValidUploadKey/unknown_type2477=== CONT TestUploadHandlersRejectOversizedBody24782026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.82ms)24792026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000024802026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.6ms)24812026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.42ms)24822026/10/01 10:03:04 OK 3_commit_push.sql (1.02ms)24832026/10/01 10:03:04 goose: up to current file version: 324842026/10/01 10:03:04 INFO lead: acquired remote=192.0.2.1:123424852026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures24862026-10-01 10:03:04.823 UTC [1536] ERROR: relation "goose_db_version" does not exist at character 3624872026-10-01 10:03:04.823 UTC [1536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24882026/10/01 10:03:04 INFO lead: released remote=192.0.2.1:12342489--- PASS: TestLeadElectsOneAndHandsOver (0.61s)2490=== CONT TestGenerateLandingPage2491--- PASS: TestGenerateLandingPage (0.00s)2492=== CONT TestCreatePendingClosureRejectsOversizedNAR24932026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures2494--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2495=== CONT TestCacheConfigHandlerMaxNarSize2496--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2497=== CONT TestService_readinessHandler24982026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures24992026-10-01 10:03:04.835 UTC [1538] ERROR: relation "goose_db_version" does not exist at character 3625002026-10-01 10:03:04.835 UTC [1538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25012026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.75ms)25022026/10/01 10:03:04 INFO Received cleanup request method=DELETE path=/api/pending_closures25032026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)25042026-10-01 10:03:04.842 UTC [1540] ERROR: relation "goose_db_version" does not exist at character 3625052026-10-01 10:03:04.842 UTC [1540] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25062026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.56ms)25072026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)25082026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.24ms)25092026/10/01 10:03:04 OK 20260905000000_add_claims.sql (2.91ms)25102026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)25112026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.43ms)25122026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.46ms)25132026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.79ms)25142026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000025152026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.23ms)25162026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.09ms)25172026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)25182026/10/01 10:03:04 OK 2_object_stats_trigger.sql (798.23µs)25192026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)25202026/10/01 10:03:04 OK 3_commit_push.sql (562.65µs)25212026/10/01 10:03:04 goose: up to current file version: 325222026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.1ms)25232026/10/01 10:03:04 OK 20251218171726_add_pins.sql (3.3ms)25242026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (1.89ms)25252026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (1.98ms)25262026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000025272026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)25282026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.29ms)25292026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.1ms)25302026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.49ms)25312026/10/01 10:03:04 OK 3_commit_push.sql (1ms)25322026/10/01 10:03:04 goose: up to current file version: 325332026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.93ms)25342026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (1.96ms)25352026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000025362026/10/01 10:03:04 OK 1_commit_pending_closure.sql (1.95ms)25372026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.05ms)25382026/10/01 10:03:04 OK 3_commit_push.sql (1.21ms)25392026/10/01 10:03:04 goose: up to current file version: 325402026/10/01 10:03:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25412026/10/01 10:03:04 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2542--- PASS: TestCompleteMultipartUnregistered (0.47s)2543=== CONT TestService_cleanupPendingClosuresHandler2544--- PASS: TestReadProxy404 (0.48s)2545=== CONT TestResolveDBConnectionString/flag_wins2546=== CONT TestResolveDBConnectionString/nothing_configured2547=== CONT TestResolveDBConnectionString/missing_file_is_an_error2548=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2549=== CONT TestResolveDBConnectionString/file_when_flag_empty2550=== CONT TestProxyWriteTimeout/narinfo2551=== CONT TestProxyWriteTimeout/10_GiB_nar2552=== CONT TestProxyWriteTimeout/unknown_size2553=== CONT TestProxyWriteTimeout/1_GiB_nar2554--- PASS: TestProxyWriteTimeout (0.00s)2555 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2556 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2557 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2558 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2559=== CONT TestClientErrorHandling/InvalidStorePath2560--- PASS: TestResolveDBConnectionString (0.00s)2561 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2562 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2563 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2564 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2565 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)25662026-10-01 10:03:04.898 UTC [1543] ERROR: relation "goose_db_version" does not exist at character 3625672026-10-01 10:03:04.898 UTC [1543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25682026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures25692026/10/01 10:03:04 OK 20241026095416_initial_model.sql (13.46ms)25702026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)25712026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.55ms)25722026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)2573--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.49s)2574=== CONT TestClientErrorHandling/ServerNotAvailable25752026/10/01 10:03:04 OK 20260905000000_add_claims.sql (4.01ms)25762026/10/01 10:03:04 OK 20260920000000_drop_claims.sql (2.83ms)2577--- PASS: TestReadProxyNarStreaming (0.49s)2578=== CONT TestClientErrorHandling/InvalidAuthToken25792026/10/01 10:03:04 OK 20260923120000_add_pushes.sql (2.66ms)25802026/10/01 10:03:04 goose: successfully migrated database to version: 2026092312000025812026/10/01 10:03:04 OK 1_commit_pending_closure.sql (2.6ms)25822026/10/01 10:03:04 OK 2_object_stats_trigger.sql (1.52ms)25832026/10/01 10:03:04 OK 3_commit_push.sql (1.31ms)25842026/10/01 10:03:04 goose: up to current file version: 325852026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures25862026/10/01 10:03:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33063/oidc2587=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure2588=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure2589=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart2590=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart2591=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts2592=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts2593=== CONT TestCacheConfigHandler/full_config,_no_issuer2594=== CONT TestCacheConfigHandler/no_signing_keys2595=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2596=== CONT TestCacheConfigHandler/no_cache_url_configured2597--- PASS: TestCacheConfigHandler (0.00s)2598 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2599 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2600 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2601 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2602=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows26032026-10-01 10:03:04.966 UTC [1555] ERROR: relation "goose_db_version" does not exist at character 3626042026-10-01 10:03:04.966 UTC [1555] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26052026-10-01 10:03:04.968 UTC [1558] ERROR: relation "goose_db_version" does not exist at character 3626062026-10-01 10:03:04.968 UTC [1558] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26072026/10/01 10:03:04 INFO Received uploads request method=POST path=/api/pending_closures26082026/10/01 10:03:04 OK 20241026095416_initial_model.sql (10.77ms)2609=== NAME TestOrphanedObjectsGC2610 orphaned_objects_gc_test.go:290: GC Test Summary:2611 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2612 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2613 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2614 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2615 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2616--- PASS: TestOrphanedObjectsGC (0.70s)2617=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check26182026/10/01 10:03:04 OK 20241026095416_initial_model.sql (11.45ms)26192026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)26202026/10/01 10:03:04 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)26212026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.31ms)26222026/10/01 10:03:04 OK 20251218171726_add_pins.sql (4.37ms)26232026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)26242026/10/01 10:03:04 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)26252026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.14ms)26262026/10/01 10:03:04 OK 20260905000000_add_claims.sql (3.73ms)26272026/10/01 10:03:05 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/present26282026/10/01 10:03:05 OK 20260920000000_drop_claims.sql (8.6ms)26292026/10/01 10:03:05 OK 20260920000000_drop_claims.sql (8.68ms)2630--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.45s)2631=== CONT TestPush_RejectsBadRequests/no_objects26322026/10/01 10:03:05 INFO Received push request method=POST path=/api/pushes2633=== CONT TestPush_RejectsBadRequests/no_roots26342026/10/01 10:03:05 INFO Received push request method=POST path=/api/pushes2635=== CONT TestPush_RejectsBadRequests/root_not_in_objects26362026/10/01 10:03:05 INFO Received push request method=POST path=/api/pushes2637=== CONT TestPush_RejectsBadRequests/bad_root26382026/10/01 10:03:05 INFO Received push request method=POST path=/api/pushes2639=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2640--- PASS: TestPush_RejectsBadRequests (0.87s)2641 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2642 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2643 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2644 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)26452026/10/01 10:03:05 OK 20260923120000_add_pushes.sql (4.38ms)26462026/10/01 10:03:05 goose: successfully migrated database to version: 2026092312000026472026/10/01 10:03:05 OK 20260923120000_add_pushes.sql (4.47ms)26482026/10/01 10:03:05 goose: successfully migrated database to version: 202609231200002649=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected26502026/10/01 10:03:05 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]2651=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26522026/10/01 10:03:05 OK 1_commit_pending_closure.sql (2.72ms)26532026/10/01 10:03:05 OK 1_commit_pending_closure.sql (3.28ms)26542026/10/01 10:03:05 WARN Authentication failed token_preview=eyJhbGciOi...hCf11tu4ng token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2655=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2656=== CONT TestIsValidCachePath/narinfo2657=== CONT TestIsValidCachePath/short_hash2658=== CONT TestIsValidCachePath/wrong_extension2659=== CONT TestIsValidCachePath/leading_slash2660=== CONT TestIsValidCachePath/empty2661=== CONT TestIsValidCachePath/random_path2662=== CONT TestIsValidCachePath/invalid_char_u2663=== CONT TestIsValidCachePath/invalid_char_e2664=== CONT TestIsValidCachePath/traversal_in_middle2665=== CONT TestIsValidCachePath/traversal_parent2666=== CONT TestIsValidCachePath/index.html2667=== CONT TestIsValidCachePath/nix-cache-info2668=== CONT TestIsValidCachePath/realisation2669=== CONT TestIsValidCachePath/log2670=== CONT TestIsValidCachePath/ls2671=== CONT TestIsValidCachePath/nar_zst2672=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2673=== CONT TestIsValidCachePath/nar_uncompressed2674=== CONT TestIsValidCachePath/nar_bz22675=== CONT TestIsValidCachePath/nar_xz2676--- PASS: TestIsValidCachePath (0.00s)2677 --- PASS: TestIsValidCachePath/narinfo (0.00s)2678 --- PASS: TestIsValidCachePath/short_hash (0.00s)2679 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2680 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2681 --- PASS: TestIsValidCachePath/empty (0.00s)2682 --- PASS: TestIsValidCachePath/random_path (0.00s)2683 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2684 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2685 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2686 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2687 --- PASS: TestIsValidCachePath/index.html (0.00s)2688 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2689 --- PASS: TestIsValidCachePath/realisation (0.00s)2690 --- PASS: TestIsValidCachePath/log (0.00s)2691 --- PASS: TestIsValidCachePath/ls (0.00s)2692 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2693 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2694 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2695 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2696 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2697=== CONT TestServerTLSConfig/no_client_CA2698=== CONT TestServerTLSConfig/missing_CA_file2699=== CONT TestServerTLSConfig/not_a_PEM_file2700--- PASS: TestService_AuthMiddleware_OIDC (0.49s)2701 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2702 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2703 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2704 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)27052026/10/01 10:03:05 OK 2_object_stats_trigger.sql (1.95ms)2706=== CONT TestService_RequireScope_OIDC/builder_may_write2707--- PASS: TestServerTLSConfig (0.00s)2708 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2709 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2710 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)27112026/10/01 10:03:05 OK 2_object_stats_trigger.sql (1.95ms)2712=== CONT TestService_RequireScope_OIDC/static_token_may_admin2713=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2714=== CONT TestService_RequireScope_OIDC/writer_implies_read2715=== CONT TestService_RequireScope_OIDC/static_token_may_write27162026/10/01 10:03:05 OK 3_commit_push.sql (1.49ms)2717=== CONT TestService_RequireScope_OIDC/ops_may_not_write27182026/10/01 10:03:05 goose: up to current file version: 32719=== CONT TestService_RequireScope_OIDC/reader_may_read2720=== CONT TestService_RequireScope_OIDC/ops_may_admin2721=== CONT TestService_RequireScope_OIDC/reader_may_not_write27222026/10/01 10:03:05 OK 3_commit_push.sql (1.47ms)27232026/10/01 10:03:05 goose: up to current file version: 32724=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2725=== CONT TestParseSingleRange/none2726=== CONT TestParseSingleRange/suffix2727=== CONT TestParseSingleRange/suffix_exceeds_size2728=== CONT TestParseSingleRange/end_clamped_to_size2729=== CONT TestParseSingleRange/open-ended2730=== CONT TestParseSingleRange/closed2731=== CONT TestParseSingleRange/malformed_end_before_start2732=== CONT TestParseSingleRange/multi-range_ignored2733=== CONT TestParseSingleRange/unknown_unit2734=== CONT TestParseSingleRange/start_past_EOF2735=== CONT TestParseSingleRange/malformed_no_dash2736=== CONT TestParseSingleRange/start_far_past_EOF2737=== CONT TestParseSingleRange/malformed_both_empty2738=== CONT TestParseSingleRange/single_byte2739--- PASS: TestParseSingleRange (0.00s)2740 --- PASS: TestParseSingleRange/none (0.00s)2741 --- PASS: TestParseSingleRange/suffix (0.00s)2742 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2743 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2744 --- PASS: TestParseSingleRange/open-ended (0.00s)2745 --- PASS: TestParseSingleRange/closed (0.00s)2746 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2747 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2748 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2749 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2750 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2751 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2752 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2753 --- PASS: TestParseSingleRange/single_byte (0.00s)2754=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info27552026/10/01 10:03:05 INFO Received uploads request method=POST path=/2756=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2757--- PASS: TestService_RequireScope_OIDC (0.83s)2758 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2759 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2760 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2761 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2762 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2763 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2764 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2765 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2766 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2767 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)27682026/10/01 10:03:05 INFO Received complete multipart upload request method=POST path=/2769=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key27702026/10/01 10:03:05 INFO Received request for more parts method=POST path=/2771=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal27722026/10/01 10:03:05 INFO Received uploads request method=POST path=/2773--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2774 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2775 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2776 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2777 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2778=== CONT TestIsValidUploadKey/narinfo2779=== CONT TestIsValidUploadKey/realisation_plus_in_output2780=== CONT TestIsValidUploadKey/unknown_type2781=== CONT TestIsValidUploadKey/empty_key2782=== CONT TestIsValidUploadKey/absolute2783=== CONT TestIsValidUploadKey/traversal_nar2784=== CONT TestIsValidUploadKey/traversal2785=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2786=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2787=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2788=== CONT TestIsValidUploadKey/index.html2789=== CONT TestIsValidUploadKey/nix-cache-info2790=== CONT TestIsValidUploadKey/build_log_home-manager_file2791=== CONT TestIsValidUploadKey/realisation2792=== CONT TestIsValidUploadKey/build_log_equals2793=== CONT TestIsValidUploadKey/build_log_question_mark2794=== CONT TestIsValidUploadKey/build_log_plus_in_name2795=== CONT TestIsValidUploadKey/nar_xz2796=== CONT TestIsValidUploadKey/build_log2797=== CONT TestIsValidUploadKey/listing2798=== CONT TestIsValidUploadKey/nar_zst2799=== CONT TestIsValidUploadKey/nar_plain2800=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure28012026/10/01 10:03:05 INFO Received uploads request method=POST path=/2802--- PASS: TestIsValidUploadKey (0.00s)2803 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2804 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2805 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2806 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2807 --- PASS: TestIsValidUploadKey/absolute (0.00s)2808 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2809 --- PASS: TestIsValidUploadKey/traversal (0.00s)2810 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2811 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2812 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2813 --- PASS: TestIsValidUploadKey/index.html (0.00s)2814 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2815 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2816 --- PASS: TestIsValidUploadKey/realisation (0.00s)2817 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2818 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2819 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2820 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2821 --- PASS: TestIsValidUploadKey/build_log (0.00s)2822 --- PASS: TestIsValidUploadKey/listing (0.00s)2823 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2824 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)28252026-10-01 10:03:05.023 UTC [1600] ERROR: relation "goose_db_version" does not exist at character 3628262026-10-01 10:03:05.023 UTC [1600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28272026-10-01 10:03:05.031 UTC [1601] ERROR: relation "goose_db_version" does not exist at character 3628282026-10-01 10:03:05.031 UTC [1601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2829--- PASS: TestReadProxyNarinfo (0.46s)2830=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart28312026/10/01 10:03:05 INFO Received complete multipart upload request method=POST path=/28322026/10/01 10:03:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete28332026/10/01 10:03:05 OK 20241026095416_initial_model.sql (11.07ms)28342026/10/01 10:03:05 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)28352026-10-01 10:03:05.042 UTC [1602] ERROR: relation "goose_db_version" does not exist at character 3628362026-10-01 10:03:05.042 UTC [1602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28372026/10/01 10:03:05 OK 20251218171726_add_pins.sql (3.62ms)28382026/10/01 10:03:05 OK 20241026095416_initial_model.sql (10.2ms)28392026/10/01 10:03:05 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)28402026/10/01 10:03:05 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)28412026/10/01 10:03:05 OK 20260905000000_add_claims.sql (2.92ms)28422026/10/01 10:03:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3Ljg3MmYzMDhjLThlOTAtNDI5My1hMGVjLWRlYjYyNGY1ZmRjM3gxNzkwODQ4OTg0NzEyMzI4NDgw parts=1028432026/10/01 10:03:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete28442026/10/01 10:03:05 OK 20251218171726_add_pins.sql (3.06ms)28452026/10/01 10:03:05 OK 20260920000000_drop_claims.sql (1.96ms)28462026/10/01 10:03:05 INFO Completed upload id=128472026/10/01 10:03:05 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)28482026/10/01 10:03:05 OK 20260923120000_add_pushes.sql (1.94ms)28492026/10/01 10:03:05 goose: successfully migrated database to version: 2026092312000028502026/10/01 10:03:05 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000028512026/10/01 10:03:05 INFO Received uploads request method=POST path=/api/pending_closures28522026/10/01 10:03:05 OK 1_commit_pending_closure.sql (2.83ms)28532026/10/01 10:03:05 OK 20260905000000_add_claims.sql (3.46ms)28542026/10/01 10:03:05 OK 20241026095416_initial_model.sql (10.88ms)28552026-10-01 10:03:05.060 UTC [1603] ERROR: relation "goose_db_version" does not exist at character 3628562026-10-01 10:03:05.060 UTC [1603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28572026/10/01 10:03:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures28582026/10/01 10:03:05 OK 2_object_stats_trigger.sql (1.15ms)28592026/10/01 10:03:05 OK 20260920000000_drop_claims.sql (2.43ms)28602026/10/01 10:03:05 OK 3_commit_push.sql (1.79ms)28612026/10/01 10:03:05 goose: up to current file version: 328622026/10/01 10:03:05 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)28632026/10/01 10:03:05 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket17266160/001/proxy.sock28642026/10/01 10:03:05 INFO Starting HTTP server address=127.0.0.1:3932328652026/10/01 10:03:05 WARN mTLS auth: subject not in bound subjects subject="CN=someone"28662026/10/01 10:03:05 OK 20260923120000_add_pushes.sql (9.6ms)28672026/10/01 10:03:05 goose: successfully migrated database to version: 2026092312000028682026/10/01 10:03:05 INFO Aborted multipart uploads count=0 kept=028692026/10/01 10:03:05 INFO Shutdown signal received, draining in-flight requests timeout=10s2870--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.46s)2871=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts28722026/10/01 10:03:05 INFO Received request for more parts method=POST path=/28732026/10/01 10:03:05 OK 20251218171726_add_pins.sql (3.59ms)28742026/10/01 10:03:05 OK 1_commit_pending_closure.sql (2.22ms)28752026/10/01 10:03:05 OK 2_object_stats_trigger.sql (1.18ms)28762026/10/01 10:03:05 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)28772026/10/01 10:03:05 OK 3_commit_push.sql (900.51µs)28782026/10/01 10:03:05 goose: up to current file version: 328792026/10/01 10:03:05 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=028802026/10/01 10:03:05 OK 20260905000000_add_claims.sql (3.38ms)28812026/10/01 10:03:05 INFO Vacuumed table table=pending_closures28822026/10/01 10:03:05 OK 20241026095416_initial_model.sql (8.83ms)28832026/10/01 10:03:05 OK 20260920000000_drop_claims.sql (2.54ms)28842026/10/01 10:03:05 INFO Vacuumed table table=pending_objects28852026/10/01 10:03:05 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)28862026/10/01 10:03:05 OK 20260923120000_add_pushes.sql (3.16ms)28872026/10/01 10:03:05 goose: successfully migrated database to version: 2026092312000028882026/10/01 10:03:05 OK 20251218171726_add_pins.sql (2.93ms)28892026/10/01 10:03:05 INFO Vacuumed table table=multipart_uploads28902026/10/01 10:03:05 OK 1_commit_pending_closure.sql (2.25ms)28912026/10/01 10:03:05 INFO Vacuumed table table=closures28922026/10/01 10:03:05 OK 2_object_stats_trigger.sql (912.27µs)28932026/10/01 10:03:05 INFO Vacuumed table table=objects28942026/10/01 10:03:05 OK 3_commit_push.sql (1.04ms)28952026/10/01 10:03:05 goose: up to current file version: 328962026/10/01 10:03:05 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)28972026/10/01 10:03:05 OK 20260905000000_add_claims.sql (2.88ms)2898=== NAME TestNARDeduplicationMetadataUploadBug2899 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2921655588/001/store/w0iivhzpkvx6g1h449czysn5cvwlzqdy-file1.txt29002026/10/01 10:03:05 INFO Received cleanup request method=DELETE path=/api/pending_closures29012026/10/01 10:03:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"29022026/10/01 10:03:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2903--- PASS: TestService_NativeMTLS (0.40s)29042026/10/01 10:03:05 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket70/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""29052026/10/01 10:03:05 INFO Aborted multipart uploads count=0 kept=129062026/10/01 10:03:05 OK 20260920000000_drop_claims.sql (3.18ms)29072026/10/01 10:03:05 OK 20260923120000_add_pushes.sql (1.91ms)29082026/10/01 10:03:05 goose: successfully migrated database to version: 2026092312000029092026/10/01 10:03:05 OK 1_commit_pending_closure.sql (1.98ms)29102026/10/01 10:03:05 INFO Received cleanup request method=DELETE path=/api/pending_closures29112026/10/01 10:03:05 OK 2_object_stats_trigger.sql (1.1ms)29122026/10/01 10:03:05 OK 3_commit_push.sql (720.11µs)29132026/10/01 10:03:05 goose: up to current file version: 329142026/10/01 10:03:05 INFO Aborted multipart uploads count=1 kept=029152026/10/01 10:03:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.859334ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2916--- PASS: TestMultipartCleanup (0.57s)29172026/10/01 10:03:05 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002918--- PASS: TestService_createPendingClosureHandler (0.81s)2919--- PASS: TestMetricsInventory (0.38s)2920--- PASS: TestPresentReportsOnlyClosureRoots (0.39s)29212026/10/01 10:03:05 INFO Received push request method=POST path=/api/pushes29222026/10/01 10:03:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29232026/10/01 10:03:05 INFO Uploading w0iivhzpkvx6g1h449czysn5cvwlzqdy-file1.txt (160B)29242026/10/01 10:03:05 WARN readiness check failed error="closed pool"2925--- PASS: TestService_readinessHandler (0.34s)29262026/10/01 10:03:05 WARN Failed to register uploaded object key=w0iivhzpkvx6g1h449czysn5cvwlzqdy.ls error="server returned 404: 404 page not found\n"29272026/10/01 10:03:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29282026/10/01 10:03:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"29292026/10/01 10:03:05 INFO Signed narinfos id=1 count=129302026/10/01 10:03:05 INFO Uploading 1 narinfos29312026/10/01 10:03:05 INFO Received complete push request method=POST path=/api/pushes/1/complete29322026/10/01 10:03:05 WARN Failed to register uploaded object key=w0iivhzpkvx6g1h449czysn5cvwlzqdy.narinfo error="server returned 404: 404 page not found\n"29332026/10/01 10:03:05 INFO Upload complete. (59ms)2934=== NAME TestNARDeduplicationMetadataUploadBug2935 metadata_upload_test.go:54: Retrieved narinfo from S3:2936 StorePath: /build/TestNARDeduplicationMetadataUploadBug2921655588/001/store/w0iivhzpkvx6g1h449czysn5cvwlzqdy-file1.txt2937 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2938 Compression: zstd2939 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2940 NarSize: 1602941 References: 2942 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2943 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2944 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2945 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}29462026/10/01 10:03:05 INFO Received cleanup request method=DELETE path=/api/pending_closures29472026/10/01 10:03:05 INFO Aborted multipart uploads count=0 kept=029482026/10/01 10:03:05 INFO Received uploads request method=POST path=/api/pending_closures29492026/10/01 10:03:05 INFO Received cleanup request method=DELETE path=/api/pending_closures29502026/10/01 10:03:05 INFO Aborted multipart uploads count=1 kept=029512026/10/01 10:03:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete29522026-10-01 10:03:05.210 UTC [1555] ERROR: Closure does not exist: id=129532026-10-01 10:03:05.210 UTC [1555] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE29542026-10-01 10:03:05.210 UTC [1555] STATEMENT: -- name: CommitPendingClosure :exec2955 SELECT commit_pending_closure($1::bigint)2956 2957--- PASS: TestService_cleanupPendingClosuresHandler (0.32s)2958=== NAME TestNARDeduplicationMetadataUploadBug2959 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2921655588/001/store/07wknsix8c8n0xvnjzrp8q5iznk89afa-file2.txt29602026/10/01 10:03:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29612026/10/01 10:03:05 WARN Refused reserved pin name=worker-x86_64-linux29622026/10/01 10:03:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29632026/10/01 10:03:05 INFO Received create pin request method=POST path=/api/pins/my-app29642026/10/01 10:03:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2965--- PASS: TestCreatePin_ReservedPins (0.48s)29662026/10/01 10:03:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete29672026/10/01 10:03:05 INFO Received uploads request method=POST path=/api/pending_closures29682026/10/01 10:03:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Mjk2OWMxZGUtMmJlZC00N2VlLWJhZGQtN2ZlYzlmZDM4MWM3LjY1MWZjYzYxLTI1YmUtNGU5ZS05MTM4LWY4ZWZhYzhhNzM2OXgxNzkwODQ4OTg0OTYwNjQ5MTA0 parts=1029692026/10/01 10:03:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete29702026/10/01 10:03:05 INFO Completed upload id=129712026/10/01 10:03:05 INFO Received uploads request method=POST path=/api/pending_closures29722026/10/01 10:03:05 INFO Aborted multipart uploads count=0 kept=029732026/10/01 10:03:05 INFO Received uploads request method=POST path=/api/pending_closures29742026/10/01 10:03:05 WARN Force mode enabled - objects will be deleted immediately without grace period29752026/10/01 10:03:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo29762026/10/01 10:03:05 WARN Found objects in DB but missing from S3, will re-upload count=12977--- PASS: TestService_verifyS3Integrity (0.82s)29782026/10/01 10:03:05 INFO Received uploads request method=POST path=/api/pending_closures29792026/10/01 10:03:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029802026/10/01 10:03:05 INFO Vacuumed table table=pending_closures29812026/10/01 10:03:05 INFO Vacuumed table table=pending_objects29822026/10/01 10:03:05 INFO Vacuumed table table=multipart_uploads29832026/10/01 10:03:05 INFO Vacuumed table table=closures29842026/10/01 10:03:05 INFO Vacuumed table table=objects29852026/10/01 10:03:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29862026/10/01 10:03:05 INFO Received push request method=POST path=/api/pushes29872026/10/01 10:03:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)29882026/10/01 10:03:05 INFO Aborted multipart uploads count=0 kept=029892026/10/01 10:03:05 WARN Force mode enabled - objects will be deleted immediately without grace period29902026/10/01 10:03:05 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign29912026/10/01 10:03:05 INFO Signed narinfos id=2 count=129922026/10/01 10:03:05 WARN Failed to register uploaded object key=07wknsix8c8n0xvnjzrp8q5iznk89afa.ls error="server returned 404: 404 page not found\n"29932026/10/01 10:03:05 INFO Uploading 1 narinfos29942026/10/01 10:03:05 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=029952026/10/01 10:03:05 INFO Vacuumed table table=pending_closures29962026/10/01 10:03:05 INFO Received complete push request method=POST path=/api/pushes/2/complete29972026/10/01 10:03:05 WARN Failed to register uploaded object key=07wknsix8c8n0xvnjzrp8q5iznk89afa.narinfo error="server returned 404: 404 page not found\n"29982026/10/01 10:03:05 INFO Vacuumed table table=pending_objects29992026/10/01 10:03:05 INFO Vacuumed table table=multipart_uploads30002026/10/01 10:03:05 INFO Vacuumed table table=closures30012026/10/01 10:03:05 INFO Vacuumed table table=objects30022026/10/01 10:03:05 INFO Upload complete. (48ms)30032026/10/01 10:03:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.630936ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3004=== NAME TestNARDeduplicationMetadataUploadBug3005 metadata_upload_test.go:76: Retrieved narinfo from S3:3006 StorePath: /build/TestNARDeduplicationMetadataUploadBug2921655588/001/store/07wknsix8c8n0xvnjzrp8q5iznk89afa-file2.txt3007 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst3008 Compression: zstd3009 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3010 NarSize: 1603011 References: 3012 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3013 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)3014 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):3015 {"version":1,"root":{"type":"regular","size":44}}3016--- PASS: TestNARDeduplicationMetadataUploadBug (0.71s)3017--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3018 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.35s)3019 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.34s)30202026/10/01 10:03:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"3021--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.88s)30222026/10/01 10:03:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=807.745647ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30232026/10/01 10:03:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=030242026/10/01 10:03:05 INFO Received create pin request method=POST path=/api/pins/myapp30252026/10/01 10:03:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1729877996/001/store/viaq9ki81jp1qv0i2cdmb5kz9l0xi89r-pinned-file.txt narinfo_key=viaq9ki81jp1qv0i2cdmb5kz9l0xi89r.narinfo30262026/10/01 10:03:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures30272026/10/01 10:03:05 INFO Garbage collection started30282026/10/01 10:03:05 INFO Aborted multipart uploads count=0 kept=030292026/10/01 10:03:05 WARN Force mode enabled - objects will be deleted immediately without grace period30302026/10/01 10:03:05 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=030312026/10/01 10:03:05 INFO Vacuumed table table=pending_closures30322026/10/01 10:03:05 INFO Vacuumed table table=pending_objects30332026/10/01 10:03:05 INFO Vacuumed table table=multipart_uploads30342026/10/01 10:03:05 INFO Vacuumed table table=closures30352026/10/01 10:03:05 INFO Vacuumed table table=objects30362026/10/01 10:03:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03037=== NAME TestClientIntegration3038 client_integration_test.go:323: Objects in database after GC:3039 client_integration_test.go:323: Successfully deleted all objects with GC --force3040--- PASS: TestClientIntegration (2.85s)3041=== NAME TestOrphanedObjectsGCStressTest3042 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains3043 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion3044--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)3045 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)3046 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)3047 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.94s)3048=== NAME TestOrphanedObjectsGCStressTest3049 orphaned_objects_gc_test.go:509: Stress test completed successfully:3050 orphaned_objects_gc_test.go:510: - Active objects preserved: 203051 orphaned_objects_gc_test.go:511: - Objects deleted: 2103052 orphaned_objects_gc_test.go:512: - Total GC'd: 2103053--- PASS: TestOrphanedObjectsGCStressTest (1.91s)30542026/10/01 10:03:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.450116679s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3055=== NAME TestPinProtectsFromGC3056 client_integration_test.go:840: Pin successfully protected closure from garbage collection3057--- PASS: TestPinProtectsFromGC (4.88s)30582026/10/01 10:03:07 WARN Rate limiter enabled after throttle name=s3-test rate=530592026/10/01 10:03:07 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3060=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3061 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103062 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003063--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.94s)30642026/10/01 10:03:07 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-config30652026/10/01 10:03:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.970108ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30662026/10/01 10:03:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.759249ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30672026/10/01 10:03:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=823.162975ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30682026/10/01 10:03:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.518623605s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30692026/10/01 10:03:10 INFO Aborted multipart uploads count=1 kept=030702026/10/01 10:03:10 INFO Received cleanup request method=DELETE path=/api/pending_closures30712026/10/01 10:03:10 INFO Aborted multipart uploads count=1 kept=03072--- PASS: TestPendingCleanupUsesOneCutoff (6.47s)30732026/10/01 10:03:11 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"30742026/10/01 10:03:11 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-config30752026/10/01 10:03:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.419026ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30762026/10/01 10:03:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.95ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30772026/10/01 10:03:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=819.080942ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30782026/10/01 10:03:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.503063141s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30792026/10/01 10:03:14 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_closures30802026/10/01 10:03:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.334502ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30812026/10/01 10:03:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.232032ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30822026/10/01 10:03:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=796.724547ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30832026/10/01 10:03:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.674467061s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3084--- PASS: TestClientErrorHandling (0.00s)3085 --- PASS: TestClientErrorHandling/InvalidStorePath (0.35s)3086 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.40s)3087 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.37s)3088PASS30892026-10-01 10:03:17.539 UTC [128] LOG: received smart shutdown request30902026-10-01 10:03:17.542 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 130912026-10-01 10:03:17.552 UTC [133] LOG: shutting down30922026-10-01 10:03:17.552 UTC [133] LOG: checkpoint starting: shutdown immediate30932026-10-01 10:03:18.068 UTC [133] LOG: checkpoint complete: wrote 10843 buffers (66.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.186 s, sync=0.309 s, total=0.517 s; sync files=28648, longest=0.091 s, average=0.001 s; distance=396534 kB, estimate=396534 kB; lsn=0/19AA36C0, redo lsn=0/19AA36C030942026-10-01 10:03:18.132 UTC [128] LOG: database system is shut down3095Running OIDC tests...3096=== RUN TestAudienceForIssuer3097=== PAUSE TestAudienceForIssuer3098=== RUN TestGlobMatch3099=== PAUSE TestGlobMatch3100=== RUN TestValidateToken_ValidToken3101=== PAUSE TestValidateToken_ValidToken3102=== RUN TestValidateToken_WrongAudience3103=== PAUSE TestValidateToken_WrongAudience3104=== RUN TestValidateToken_Expired3105=== PAUSE TestValidateToken_Expired3106=== RUN TestValidateToken_BoundClaimsMismatch3107=== PAUSE TestValidateToken_BoundClaimsMismatch3108=== RUN TestValidateToken_BoundSubjectMismatch3109=== PAUSE TestValidateToken_BoundSubjectMismatch3110=== RUN TestValidateToken_MultipleProviders3111=== PAUSE TestValidateToken_MultipleProviders3112=== RUN TestValidateToken_NoMatchingProvider3113=== PAUSE TestValidateToken_NoMatchingProvider3114=== RUN TestValidateToken_KubernetesServiceAccount3115=== PAUSE TestValidateToken_KubernetesServiceAccount3116=== RUN TestNewValidator_KubernetesRequiresCA3117=== PAUSE TestNewValidator_KubernetesRequiresCA3118=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3119=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3120=== RUN TestPins_ReservedForMatchingRule3121=== PAUSE TestPins_ReservedForMatchingRule3122=== RUN TestPins_TopLevelShorthand3123=== PAUSE TestPins_TopLevelShorthand3124=== RUN TestPins_ConfigValidation3125=== PAUSE TestPins_ConfigValidation3126=== RUN TestScopes_LegacyProviderDefaultsToWrite3127=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3128=== RUN TestScopes_Rules3129=== PAUSE TestScopes_Rules3130=== RUN TestScopes_ConfigValidation3131=== PAUSE TestScopes_ConfigValidation3132=== CONT TestAudienceForIssuer3133=== CONT TestPins_ConfigValidation3134=== CONT TestValidateToken_KubernetesServiceAccount3135=== CONT TestValidateToken_BoundClaimsMismatch3136--- PASS: TestAudienceForIssuer (0.00s)3137=== CONT TestValidateToken_Expired3138=== CONT TestValidateToken_WrongAudience3139=== CONT TestValidateToken_ValidToken3140=== CONT TestGlobMatch3141=== RUN TestGlobMatch/foo_foo3142=== PAUSE TestGlobMatch/foo_foo3143=== RUN TestGlobMatch/foo_bar3144=== PAUSE TestGlobMatch/foo_bar3145=== RUN TestGlobMatch/*_3146=== PAUSE TestGlobMatch/*_3147=== RUN TestGlobMatch/*_anything3148=== PAUSE TestGlobMatch/*_anything3149=== RUN TestGlobMatch/foo*_foo3150=== PAUSE TestGlobMatch/foo*_foo3151=== RUN TestGlobMatch/foo*_foobar3152=== CONT TestScopes_Rules3153=== CONT TestScopes_ConfigValidation3154=== CONT TestScopes_LegacyProviderDefaultsToWrite3155=== CONT TestPins_ReservedForMatchingRule3156=== CONT TestPins_TopLevelShorthand3157=== CONT TestValidateToken_MultipleProviders3158=== CONT TestValidateToken_NoMatchingProvider3159=== CONT TestValidateToken_BoundSubjectMismatch3160=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3161=== CONT TestNewValidator_KubernetesRequiresCA3162=== PAUSE TestGlobMatch/foo*_foobar3163=== RUN TestGlobMatch/foo*_bar3164=== PAUSE TestGlobMatch/foo*_bar3165=== RUN TestGlobMatch/*bar_bar3166=== PAUSE TestGlobMatch/*bar_bar3167=== RUN TestGlobMatch/*bar_foobar3168=== PAUSE TestGlobMatch/*bar_foobar3169=== RUN TestGlobMatch/*bar_foo3170=== PAUSE TestGlobMatch/*bar_foo3171=== RUN TestGlobMatch/foo*bar_foobar3172=== PAUSE TestGlobMatch/foo*bar_foobar3173=== RUN TestGlobMatch/foo*bar_foo123bar3174=== PAUSE TestGlobMatch/foo*bar_foo123bar3175=== RUN TestGlobMatch/foo*bar_foobarbaz3176=== PAUSE TestGlobMatch/foo*bar_foobarbaz3177=== RUN TestGlobMatch/*/*_foo/bar3178=== PAUSE TestGlobMatch/*/*_foo/bar3179=== RUN TestGlobMatch/*/*_foo3180=== PAUSE TestGlobMatch/*/*_foo3181=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3182=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3183=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03184=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03185=== RUN TestGlobMatch/refs/*/main_refs/heads/main3186=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3187=== RUN TestGlobMatch/fo?_foo3188=== PAUSE TestGlobMatch/fo?_foo3189=== RUN TestGlobMatch/fo?_fo3190=== PAUSE TestGlobMatch/fo?_fo3191=== RUN TestGlobMatch/fo?_fooo3192=== PAUSE TestGlobMatch/fo?_fooo3193=== RUN TestGlobMatch/?oo_foo3194=== PAUSE TestGlobMatch/?oo_foo3195=== RUN TestGlobMatch/?oo_boo3196=== PAUSE TestGlobMatch/?oo_boo3197=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3198=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3199=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3200=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3201=== CONT TestGlobMatch/foo_foo3202--- PASS: TestPins_ConfigValidation (0.00s)3203=== CONT TestGlobMatch/*/*_foo/bar3204=== CONT TestGlobMatch/fo?_foo3205=== CONT TestGlobMatch/refs/*/main_refs/heads/main3206=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03207=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3208=== CONT TestGlobMatch/*/*_foo3209=== CONT TestGlobMatch/*bar_bar3210=== CONT TestGlobMatch/fo?_fo3211=== CONT TestGlobMatch/foo*bar_foobarbaz3212=== CONT TestGlobMatch/foo*bar_foo123bar3213=== CONT TestGlobMatch/?oo_boo3214=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3215=== CONT TestGlobMatch/foo*_foobar3216=== CONT TestGlobMatch/*bar_foo3217=== CONT TestGlobMatch/*bar_foobar3218=== CONT TestGlobMatch/?oo_foo3219=== CONT TestGlobMatch/foo*bar_foobar3220=== CONT TestGlobMatch/foo*_bar3221=== CONT TestGlobMatch/foo*_foo3222=== CONT TestGlobMatch/*_3223=== CONT TestGlobMatch/fo?_fooo3224=== CONT TestGlobMatch/*_anything3225=== CONT TestGlobMatch/foo_bar3226=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3227--- PASS: TestGlobMatch (0.00s)3228 --- PASS: TestGlobMatch/foo_foo (0.00s)3229 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3230 --- PASS: TestGlobMatch/fo?_foo (0.00s)3231 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3232 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3233 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3234 --- PASS: TestGlobMatch/*/*_foo (0.00s)3235 --- PASS: TestGlobMatch/*bar_bar (0.00s)3236 --- PASS: TestGlobMatch/fo?_fo (0.00s)3237 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3238 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3239 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3240 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3241 --- PASS: TestGlobMatch/?oo_boo (0.00s)3242 --- PASS: TestGlobMatch/*bar_foo (0.00s)3243 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3244 --- PASS: TestGlobMatch/?oo_foo (0.00s)3245 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3246 --- PASS: TestGlobMatch/foo*_bar (0.00s)3247 --- PASS: TestGlobMatch/foo*_foo (0.00s)3248 --- PASS: TestGlobMatch/*_ (0.00s)3249 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3250 --- PASS: TestGlobMatch/*_anything (0.00s)3251 --- PASS: TestGlobMatch/foo_bar (0.00s)3252 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3253--- PASS: TestScopes_ConfigValidation (0.00s)32542026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43361/oidc3255--- PASS: TestValidateToken_WrongAudience (0.04s)32562026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44253/oidc3257--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)32582026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42061/oidc3259--- PASS: TestValidateToken_Expired (0.05s)32602026/10/01 10:03:19 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:460933261--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)32622026/10/01 10:03:19 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233263--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)32642026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37783/oidc3265--- PASS: TestValidateToken_ValidToken (0.11s)32662026/10/01 10:03:19 http: TLS handshake error from 127.0.0.1:47550: remote error: tls: bad certificate3267--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)32682026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44679/oidc3269--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)32702026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34151/oidc3271--- PASS: TestScopes_Rules (0.15s)32722026/10/01 10:03:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:32879/oidc32732026/10/01 10:03:19 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35969/oidc3274--- PASS: TestValidateToken_MultipleProviders (0.17s)32752026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42889/oidc32762026/10/01 10:03:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35015/oidc3277--- PASS: TestValidateToken_NoMatchingProvider (0.18s)3278--- PASS: TestPins_ReservedForMatchingRule (0.19s)32792026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44485/oidc3280--- PASS: TestPins_TopLevelShorthand (0.19s)32812026/10/01 10:03:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37235/oidc3282--- PASS: TestValidateToken_BoundClaimsMismatch (0.26s)3283PASS3284Running hook tests...3285=== RUN TestSendPathsEmpty3286=== PAUSE TestSendPathsEmpty3287=== RUN TestQueueEnqueueAndFetch3288=== PAUSE TestQueueEnqueueAndFetch3289=== RUN TestQueueDeduplication3290=== PAUSE TestQueueDeduplication3291=== RUN TestQueueRemove3292=== PAUSE TestQueueRemove3293=== RUN TestQueueFetchBatchLimit3294=== PAUSE TestQueueFetchBatchLimit3295=== RUN TestQueueRetryMovesToBack3296=== PAUSE TestQueueRetryMovesToBack3297=== RUN TestQueueFetchRemoveLifecycle3298=== PAUSE TestQueueFetchRemoveLifecycle3299=== RUN TestQueueConcurrentWriters3300=== PAUSE TestQueueConcurrentWriters3301=== RUN TestQueueRemoveLargeClosure3302=== PAUSE TestQueueRemoveLargeClosure3303=== RUN TestServerClientIntegration3304=== PAUSE TestServerClientIntegration3305=== RUN TestServerQueueError3306=== PAUSE TestServerQueueError3307=== RUN TestGetListenerSocketActivation3308 server_test.go:210: === RUN TestGetListenerSocketActivation3309 --- PASS: TestGetListenerSocketActivation (0.00s)3310 PASS3311 3312--- PASS: TestGetListenerSocketActivation (0.01s)3313=== RUN TestDrainIsolatesPoisonPath3314=== PAUSE TestDrainIsolatesPoisonPath3315=== RUN TestRunNotBlockedByPoisonHead3316=== PAUSE TestRunNotBlockedByPoisonHead3317=== RUN TestDrainGivesUpWhenServerDown3318=== PAUSE TestDrainGivesUpWhenServerDown3319=== RUN TestFailedPathPrunedByLaterClosure3320=== PAUSE TestFailedPathPrunedByLaterClosure3321=== RUN TestWorkerUploadsAndRemoves3322=== PAUSE TestWorkerUploadsAndRemoves3323=== RUN TestWorkerSkipsGCdPaths3324=== PAUSE TestWorkerSkipsGCdPaths3325=== RUN TestWorkerPrunesClosureDeps3326=== PAUSE TestWorkerPrunesClosureDeps3327=== RUN TestDrainTimeout3328=== PAUSE TestDrainTimeout3329=== CONT TestSendPathsEmpty3330=== CONT TestFailedPathPrunedByLaterClosure3331=== CONT TestQueueRemove3332--- PASS: TestSendPathsEmpty (0.00s)3333=== CONT TestDrainGivesUpWhenServerDown3334=== CONT TestRunNotBlockedByPoisonHead3335=== CONT TestDrainIsolatesPoisonPath3336=== CONT TestServerQueueError3337=== CONT TestServerClientIntegration3338=== CONT TestWorkerPrunesClosureDeps3339=== CONT TestQueueRemoveLargeClosure3340=== CONT TestQueueConcurrentWriters3341=== CONT TestDrainTimeout3342=== CONT TestQueueFetchRemoveLifecycle3343=== CONT TestQueueEnqueueAndFetch3344=== CONT TestQueueDeduplication33452026/10/01 10:03:19 ERROR Failed to queue paths error="permission denied" count=13346=== CONT TestQueueRetryMovesToBack3347=== CONT TestQueueFetchBatchLimit3348=== CONT TestWorkerSkipsGCdPaths3349--- PASS: TestServerClientIntegration (0.00s)3350--- PASS: TestServerQueueError (0.00s)3351=== CONT TestWorkerUploadsAndRemoves33522026/10/01 10:03:19 INFO Uploading batch count=133532026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=133542026/10/01 10:03:19 INFO Uploading batch count=433552026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=433562026/10/01 10:03:19 INFO Uploading batch count=233572026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath474683737/002/bbb33582026/10/01 10:03:19 INFO Uploading batch count=13359--- PASS: TestQueueRemove (0.02s)3360--- PASS: TestQueueFetchBatchLimit (0.01s)33612026/10/01 10:03:19 INFO Upload queue status pending=233622026/10/01 10:03:19 INFO Uploading batch count=13363--- PASS: TestQueueFetchRemoveLifecycle (0.01s)33642026/10/01 10:03:19 INFO Upload queue status pending=333652026/10/01 10:03:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3529984317/002/nonexistent33662026/10/01 10:03:19 INFO Uploading batch count=133672026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=13368--- PASS: TestQueueRetryMovesToBack (0.01s)3369--- PASS: TestQueueEnqueueAndFetch (0.01s)33702026/10/01 10:03:19 INFO Upload queue status pending=23371--- PASS: TestQueueDeduplication (0.01s)33722026/10/01 10:03:19 INFO Uploading batch count=133732026/10/01 10:03:19 INFO Upload queue status pending=233742026/10/01 10:03:19 INFO Uploading batch count=233752026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=233762026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1411091189/002/a33772026/10/01 10:03:19 INFO Uploading batch count=233782026/10/01 10:03:19 INFO Uploading batch count=133792026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1411091189/002/b33802026/10/01 10:03:19 INFO Uploading batch count=133812026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=133822026/10/01 10:03:19 INFO Uploading batch count=233832026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=23384--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)33852026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1411091189/002/c33862026/10/01 10:03:19 INFO Uploading batch count=133872026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=133882026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1411091189/002/d33892026/10/01 10:03:19 INFO Uploading batch count=133902026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=133912026/10/01 10:03:19 INFO Uploading batch count=233922026/10/01 10:03:19 ERROR Upload failed error="upload failed" count=233932026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1411091189/002/e33942026/10/01 10:03:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1411091189/002/f33952026/10/01 10:03:19 ERROR Drain finished with paths left in queue remaining=133962026/10/01 10:03:19 ERROR Drain finished with paths left in queue remaining=103397--- PASS: TestDrainIsolatesPoisonPath (0.02s)3398--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3399--- PASS: TestWorkerUploadsAndRemoves (0.03s)3400--- PASS: TestWorkerSkipsGCdPaths (0.03s)3401--- PASS: TestWorkerPrunesClosureDeps (0.03s)3402--- PASS: TestQueueConcurrentWriters (0.14s)3403--- PASS: TestQueueRemoveLargeClosure (0.15s)34042026/10/01 10:03:19 ERROR Upload failed error="context deadline exceeded" count=234052026/10/01 10:03:19 ERROR Drain finished with paths left in queue remaining=43406--- PASS: TestDrainTimeout (0.21s)34072026/10/01 10:03:20 INFO Uploading batch count=134082026/10/01 10:03:20 INFO Uploading batch count=134092026/10/01 10:03:20 INFO Uploading batch count=134102026/10/01 10:03:20 ERROR Upload failed error="upload failed" count=134112026/10/01 10:03:20 INFO Uploading batch count=134122026/10/01 10:03:20 ERROR Upload failed error="upload failed" count=134132026/10/01 10:03:20 INFO Uploading batch count=134142026/10/01 10:03:20 ERROR Upload failed error="upload failed" count=134152026/10/01 10:03:20 INFO Uploading batch count=134162026/10/01 10:03:20 ERROR Upload failed error="upload failed" count=134172026/10/01 10:03:20 ERROR Drain finished with paths left in queue remaining=13418--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3419PASS

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #329 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #329 · raw