niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #304
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97--- PASS: TestShellSplit (0.00s)98=== CONT TestScriptTokenEmptyCommand99--- PASS: TestScriptTokenEmptyCommand (0.00s)100=== CONT TestEncodeNixBase32WithRealHash101--- PASS: TestEncodeNixBase32WithRealHash (0.00s)102=== CONT TestScriptTokenScriptFails103=== CONT TestDoWithRetry_BodyReplayedViaGetBody104=== CONT TestParsePathInfoJSON105=== CONT TestPathInfoHashCompatibility106=== CONT TestUploadMultipart_SupersededByPeer107=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)108=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)109=== RUN TestUploadMultipart_SupersededByPeer/exists110=== PAUSE TestUploadMultipart_SupersededByPeer/exists111=== RUN TestUploadMultipart_SupersededByPeer/missing112=== CONT TestEncodeNixBase32113=== CONT TestDumpPathWriterError114=== CONT TestConvertHashToNix32115=== CONT TestDumpPathSingleFile116=== CONT TestDumpPathMatchesNix117=== CONT TestPartSizeForNAR118=== CONT TestParsePathInfoJSONMultiplePaths119=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess120=== CONT TestRateLimiterFeedback121=== CONT TestCaseHackSuffix122=== CONT TestResolveStorePath123=== CONT TestPathInfoCACompatibility124=== CONT TestSetClientTLSErrors125=== CONT TestStreamPushRequestLine126=== CONT TestSetClientTLS127=== CONT TestClientSignaturesByStorePath128=== CONT TestSetClientTLSDoesNotMutateDefaultTransport129=== RUN TestConvertHashToNix32/SRI_format_to_Nix32130=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32131=== RUN TestParsePathInfoJSON/Nix_format132=== CONT TestGetStorePathHash133=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon134=== CONT TestStreamPushReportsSignatures135--- PASS: TestClientSignaturesByStorePath (0.00s)136=== RUN TestEncodeNixBase32/test_string_hash137=== PAUSE TestEncodeNixBase32/test_string_hash138=== RUN TestEncodeNixBase32/empty_input139=== PAUSE TestEncodeNixBase32/empty_input140=== PAUSE TestUploadMultipart_SupersededByPeer/missing141=== RUN TestRateLimiterFeedback/429_enables_limiter142=== PAUSE TestRateLimiterFeedback/429_enables_limiter143=== CONT TestScriptTokenCachesUntilRefresh1442026/10/01 08:35:22 WARN Rate limiter enabled after throttle name=server-test rate=5145=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon146=== RUN TestPathInfoCACompatibility/null_ca_field147=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI148=== PAUSE TestParsePathInfoJSON/Nix_format149=== PAUSE TestPathInfoCACompatibility/null_ca_field150=== RUN TestParsePathInfoJSON/Lix_format151=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152--- PASS: TestScriptTokenScriptFails (0.00s)153=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI154=== RUN TestGetStorePathHash/valid_store_path155=== CONT TestFileTokenEmpty156=== RUN TestRateLimiterFeedback/503_enables_limiter157=== PAUSE TestRateLimiterFeedback/503_enables_limiter158=== CONT TestScriptTokenNoExpiryRerunsEveryCall159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestConvertHashToNix32/already_Nix32_format161=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121622026/10/01 08:35:22 WARN Rate limiter enabled after throttle name=server-test rate=5163--- PASS: TestResolveStorePath (0.00s)1642026/10/01 08:35:22 ERROR Upload failed error=boom count=1165=== RUN TestPartSizeForNAR/zero_stays_at_minimum166=== CONT TestScriptTokenEmptyToken167=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum168=== RUN TestPathInfoCACompatibility/old_string_format_-_text169=== PAUSE TestParsePathInfoJSON/Lix_format1702026/10/01 08:35:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45095171=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1722026/10/01 08:35:22 ERROR Upload failed error=boom count=1173=== PAUSE TestGetStorePathHash/valid_store_path174=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter175=== RUN TestConvertHashToNix32/invalid_format176=== RUN TestGetStorePathHash/basename_without_hyphen_should_error177=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512179=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error180=== CONT TestFileTokenReadsAndCaches181=== RUN TestPartSizeForNAR/small_stays_at_minimum182=== CONT TestUploadMultipart_PartsInParallel183=== RUN TestParsePathInfoJSON/empty_input184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text185=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186--- PASS: TestStreamPushReportsSignatures (0.01s)187--- PASS: TestDoServerRequestAttachesToken (0.01s)188=== PAUSE TestConvertHashToNix32/invalid_format189--- PASS: TestFileTokenEmpty (0.00s)190=== CONT TestScriptTokenBadJSON191=== RUN TestSetClientTLSErrors/missing_cert_file192=== CONT TestFileTokenMissing193=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error194=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive195=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error196=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive197=== RUN TestPathInfoCACompatibility/new_structured_format_-_text198=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text199=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method200=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method201=== CONT TestStaticToken202--- PASS: TestStaticToken (0.00s)203=== CONT TestStreamPushBatchesUnderLoad204=== PAUSE TestSetClientTLSErrors/missing_cert_file205--- PASS: TestFileTokenMissing (0.00s)206=== CONT TestStreamPushReportsEveryPath207=== RUN TestSetClientTLSErrors/missing_key_file208=== PAUSE TestSetClientTLSErrors/missing_key_file209=== CONT TestRegisterUploadedObjectReusesConnections210=== RUN TestSetClientTLSErrors/missing_ca_file211=== PAUSE TestSetClientTLSErrors/missing_ca_file212--- PASS: TestStreamPushReportsEveryPath (0.00s)213=== CONT TestStreamPushGivesUpOnDeadServer214=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error215=== PAUSE TestPartSizeForNAR/small_stays_at_minimum216=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter217=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum218=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum219=== CONT TestShellSplitErrors220=== RUN TestSetClientTLSErrors/invalid_ca_file221=== PAUSE TestSetClientTLSErrors/invalid_ca_file222--- PASS: TestFileTokenReadsAndCaches (0.02s)223=== CONT TestFilterOversizedClosures224--- PASS: TestScriptTokenEmptyToken (0.02s)225=== RUN TestFilterOversizedClosures/no_limit_keeps_everything226=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything227=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped228=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter229=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter230=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts231=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts232=== CONT TestUploadMultipart_SupersededByPeer/exists233=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234=== RUN TestFilterOversizedClosures/all_closures_skipped235=== RUN TestPartSizeForNAR/1_TiB236=== PAUSE TestPartSizeForNAR/1_TiB237=== RUN TestPartSizeForNAR/5_TiB_S3_max_object238=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object239=== RUN TestPartSizeForNAR/capped_at_5_GiB240=== PAUSE TestPartSizeForNAR/capped_at_5_GiB241=== CONT TestEncodeNixBase32/test_string_hash242=== CONT TestEncodeNixBase32/empty_input243--- PASS: TestEncodeNixBase32 (0.00s)244 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)245 --- PASS: TestEncodeNixBase32/empty_input (0.00s)246=== RUN TestSetClientTLS/rejects_connection_without_client_cert247--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)248=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert249=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI250=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon251=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512252=== CONT TestConvertHashToNix32/SRI_format_to_Nix32253=== CONT TestStreamPushIsolatesFailures2542026/10/01 08:35:22 ERROR Upload failed error="connection refused" count=20255=== CONT TestConvertHashToNix32/invalid_format2562026/10/01 08:35:22 ERROR Server seems unavailable, giving up on batch untried=17257=== CONT TestUploadMultipart_SupersededByPeer/missing2582026/10/01 08:35:22 ERROR Upload failed error="bad path" count=3259--- PASS: TestStreamPushIsolatesFailures (0.00s)260=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method261=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)262=== CONT TestPathInfoCACompatibility/null_ca_field263--- PASS: TestPathInfoHashCompatibility (0.01s)264 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)265 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)266 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)267 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)268=== PAUSE TestFilterOversizedClosures/all_closures_skipped269=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive270=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error271=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error272=== CONT TestGetStorePathHash/basename_without_hyphen_should_error273=== CONT TestSetClientTLSErrors/missing_key_file274=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA275=== CONT TestSetClientTLSErrors/missing_cert_file276=== CONT TestSetClientTLSErrors/missing_ca_file277=== CONT TestSetClientTLSErrors/invalid_ca_file278=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA279=== CONT TestGetStorePathHash/valid_store_path280--- PASS: TestStreamPushGivesUpOnDeadServer (0.02s)281=== CONT TestPathInfoCACompatibility/old_string_format_-_text282--- PASS: TestGetStorePathHash (0.01s)283 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)284 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)285 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)286 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)287=== PAUSE TestParsePathInfoJSON/empty_input288--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)289 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)290 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)291=== CONT TestRateLimiterFeedback/503_enables_limiter292=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths293=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum2942026/10/01 08:35:22 WARN Rate limiter backed off name=server-test rate=5295=== CONT TestRateLimiterFeedback/429_enables_limiter2962026/10/01 08:35:22 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45095297=== CONT TestPartSizeForNAR/small_stays_at_minimum298=== CONT TestPartSizeForNAR/capped_at_5_GiB299=== CONT TestConvertHashToNix32/already_Nix32_format300=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3012026/10/01 08:35:22 WARN Rate limiter enabled after throttle name=server-test rate=5302=== CONT TestFilterOversizedClosures/all_closures_skipped3032026/10/01 08:35:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:418293042026/10/01 08:35:22 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=503052026/10/01 08:35:22 WARN Rate limiter enabled after throttle name=server-test rate=5306=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3072026/10/01 08:35:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:385073082026/10/01 08:35:22 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=2000309=== RUN TestParsePathInfoJSON/whitespace_only3102026/10/01 08:35:22 WARN Rate limiter backed off name=server-test rate=5311=== PAUSE TestParsePathInfoJSON/whitespace_only312=== RUN TestSetClientTLS/preserves_debug_logging_transport313=== PAUSE TestSetClientTLS/preserves_debug_logging_transport3142026/10/01 08:35:22 WARN Rate limiter backed off name=server-test rate=5315=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter316=== CONT TestSetClientTLS/rejects_connection_without_client_cert317=== CONT TestPathInfoCACompatibility/new_structured_format_-_text318=== CONT TestPartSizeForNAR/zero_stays_at_minimum319--- PASS: TestDumpPathSingleFile (0.03s)320=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts321=== CONT TestPartSizeForNAR/5_TiB_S3_max_object322=== CONT TestPartSizeForNAR/1_TiB323=== CONT TestFilterOversizedClosures/no_limit_keeps_everything324=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths325=== RUN TestParsePathInfoJSON/invalid_JSON326=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths327=== CONT TestSetClientTLS/preserves_debug_logging_transport328=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA329--- PASS: TestShellSplitErrors (0.02s)330=== PAUSE TestParsePathInfoJSON/invalid_JSON331=== CONT TestParsePathInfoJSON/Nix_format332=== CONT TestParsePathInfoJSON/invalid_JSON333=== CONT TestParsePathInfoJSON/empty_input334=== CONT TestParsePathInfoJSON/whitespace_only335=== CONT TestParsePathInfoJSON/Lix_format336--- PASS: TestConvertHashToNix32 (0.01s)337 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)338 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)339 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)340--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)341--- PASS: TestSetClientTLSErrors (0.01s)342 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)343 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)345 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)346--- PASS: TestScriptTokenBadJSON (0.03s)347--- PASS: TestRateLimiterFeedback (0.03s)348 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)349 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)350 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)351 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)352--- PASS: TestPartSizeForNAR (0.03s)353 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)356 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)357 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)358 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)359 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)360--- PASS: TestFilterOversizedClosures (0.00s)361 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)362 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)363 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)364--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)365 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)366 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)367--- PASS: TestPathInfoCACompatibility (0.01s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)369 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)370 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)371 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)372 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)373--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)374--- PASS: TestParsePathInfoJSON (0.04s)375 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)376 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)377 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)378 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)379 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)380--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3812026/10/01 08:35:22 http: TLS handshake error from 127.0.0.1:48052: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.03s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestStreamPushRequestLine (0.05s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)388--- PASS: TestCaseHackSuffix (0.06s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestDumpPathMatchesNix (0.11s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.64s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres227992458/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/postgres227992458/data -l logfile start422423/build/postgres227992458:5432 - no response4242026-10-01 08:35:24.104 UTC [131] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 08:35:24.105 UTC [131] LOG: listening on Unix socket "/build/postgres227992458/.s.PGSQL.5432"4262026-10-01 08:35:24.110 UTC [138] LOG: database system was shut down at 2026-10-01 08:35:23 UTC4272026-10-01 08:35:24.114 UTC [131] LOG: database system is ready to accept connections428/build/postgres227992458:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-10-01 08:35:24.586 UTC [565] ERROR: relation "goose_db_version" does not exist at character 364712026-10-01 08:35:24.586 UTC [565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/10/01 08:35:24 OK 20241026095416_initial_model.sql (7.36ms)4732026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)4742026/10/01 08:35:24 OK 20251218171726_add_pins.sql (2.26ms)4752026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (1.86ms)4762026/10/01 08:35:24 OK 20260905000000_add_claims.sql (2.29ms)4772026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (1.36ms)4782026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (968.14µs)4792026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200004802026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.42ms)4812026/10/01 08:35:24 OK 2_object_stats_trigger.sql (772.32µs)4822026/10/01 08:35:24 OK 3_commit_push.sql (680.34µs)4832026/10/01 08:35:24 goose: up to current file version: 34842026/10/01 08:35:24 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 08:35:25 INFO lead: released remote=192.0.2.1:12344862026/10/01 08:35:25 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 08:35:25 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-10-01 08:35:25.349 UTC [575] ERROR: relation "goose_db_version" does not exist at character 364932026-10-01 08:35:25.349 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/10/01 08:35:25 OK 20241026095416_initial_model.sql (6.27ms)4952026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)4962026/10/01 08:35:25 OK 20251218171726_add_pins.sql (2.3ms)4972026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (2.59ms)4982026/10/01 08:35:25 OK 20260905000000_add_claims.sql (2.41ms)4992026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (1.32ms)5002026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (1.12ms)5012026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200005022026/10/01 08:35:25 OK 1_commit_pending_closure.sql (1.52ms)5032026/10/01 08:35:25 OK 2_object_stats_trigger.sql (735.81µs)5042026/10/01 08:35:25 OK 3_commit_push.sql (804.13µs)5052026/10/01 08:35:25 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestObjectStatsTrigger578=== PAUSE TestObjectStatsTrigger579=== RUN TestOrphanedObjectsGC580=== PAUSE TestOrphanedObjectsGC581=== RUN TestOrphanedObjectsGCStressTest582=== PAUSE TestOrphanedObjectsGCStressTest583=== RUN TestCreatePin_ReservedPins584=== PAUSE TestCreatePin_ReservedPins585=== RUN TestParseSingleRange586=== PAUSE TestParseSingleRange587=== RUN TestProxyHeadersOnlyTrustedOnSocket588=== PAUSE TestProxyHeadersOnlyTrustedOnSocket589=== RUN TestIsValidCachePath590=== PAUSE TestIsValidCachePath591=== RUN TestReadProxyNarinfo592=== PAUSE TestReadProxyNarinfo593=== RUN TestReadProxyNarinfoAlreadyDecompressed594=== PAUSE TestReadProxyNarinfoAlreadyDecompressed595=== RUN TestReadProxyNarStreaming596=== PAUSE TestReadProxyNarStreaming597=== RUN TestReadProxy404598=== PAUSE TestReadProxy404599=== RUN TestReadProxyInvalidPath600=== PAUSE TestReadProxyInvalidPath601=== RUN TestReadProxyHead602=== PAUSE TestReadProxyHead603=== RUN TestReadProxyConditionalGet604=== PAUSE TestReadProxyConditionalGet605=== RUN TestReadProxyRootRedirectsToIndexHTML606=== PAUSE TestReadProxyRootRedirectsToIndexHTML607=== RUN TestReadProxyDisabled608=== PAUSE TestReadProxyDisabled609=== RUN TestReadRedirectNar610=== PAUSE TestReadRedirectNar611=== RUN TestReadRedirectKeepsNarinfoProxied612=== PAUSE TestReadRedirectKeepsNarinfoProxied613=== RUN TestReadProxyRangeRequest614=== PAUSE TestReadProxyRangeRequest615=== RUN TestReadRedirectUsesPublicS3URL616=== PAUSE TestReadRedirectUsesPublicS3URL617=== RUN TestPush_OverlappingRootsStoreOneRowPerKey618=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey619=== RUN TestPush_CompleteCommitsEveryRoot620=== PAUSE TestPush_CompleteCommitsEveryRoot621=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit622=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit623=== RUN TestPush_RejectsBadRequests624=== PAUSE TestPush_RejectsBadRequests625=== RUN TestPush_SignsNarinfosOfItsPendingObjects626=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects627=== RUN TestRedundantMultipartUpload628=== PAUSE TestRedundantMultipartUpload629=== RUN TestCompleteMultipartUpload_ErrorButObjectExists630=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists631=== RUN TestCompletedNarNotReofferedAcrossClosures632=== PAUSE TestCompletedNarNotReofferedAcrossClosures633=== RUN TestPresignedUploadRegisteredBeforeCommit634=== PAUSE TestPresignedUploadRegisteredBeforeCommit635=== RUN TestService_Rustfstest636=== PAUSE TestService_Rustfstest637=== RUN TestParseSize638=== PAUSE TestParseSize639=== RUN TestSkippedUploadsHandler640=== PAUSE TestSkippedUploadsHandler641=== RUN TestSystemdListenerNotActivated642--- PASS: TestSystemdListenerNotActivated (0.00s)643=== RUN TestWatchdogBeatsWhenHealthy644--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)645=== RUN TestWatchdogSkipsWhenUnhealthy6462026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 08:35:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"656--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)657=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle658=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle659=== RUN TestProxyWriteTimeout660=== PAUSE TestProxyWriteTimeout661=== RUN TestIsValidUploadKey662=== PAUSE TestIsValidUploadKey663=== RUN TestUploadHandlersRejectInvalidKeys664=== PAUSE TestUploadHandlersRejectInvalidKeys665=== RUN TestUploadHandlersRejectOversizedBody666=== PAUSE TestUploadHandlersRejectOversizedBody667=== RUN TestService_cleanupPendingClosuresHandler668=== PAUSE TestService_cleanupPendingClosuresHandler669=== RUN TestService_createPendingClosureHandler670=== PAUSE TestService_createPendingClosureHandler671=== RUN TestService_verifyS3Integrity672=== PAUSE TestService_verifyS3Integrity673=== RUN TestCompleteMultipartUnregistered674=== PAUSE TestCompleteMultipartUnregistered675=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT676=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT677=== CONT TestService_AuthMiddleware678=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT679=== CONT TestReadProxyRangeRequest680=== CONT TestCompleteMultipartUnregistered681=== CONT TestService_verifyS3Integrity682=== CONT TestService_createPendingClosureHandler683=== CONT TestService_cleanupPendingClosuresHandler684=== CONT TestUploadHandlersRejectOversizedBody685=== CONT TestUploadHandlersRejectInvalidKeys686=== CONT TestIsValidUploadKey687=== CONT TestProxyWriteTimeout688=== RUN TestProxyWriteTimeout/narinfo689=== PAUSE TestProxyWriteTimeout/narinfo690=== RUN TestProxyWriteTimeout/1_GiB_nar691=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle692=== CONT TestSkippedUploadsHandler693=== CONT TestParseSize694--- PASS: TestParseSize (0.00s)695=== CONT TestService_Rustfstest696=== CONT TestPresignedUploadRegisteredBeforeCommit6972026/10/01 08:35:25 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000698=== CONT TestCompletedNarNotReofferedAcrossClosures699=== CONT TestCompleteMultipartUpload_ErrorButObjectExists700=== CONT TestRedundantMultipartUpload701=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info702=== CONT TestPush_SignsNarinfosOfItsPendingObjects703=== CONT TestPush_RejectsBadRequests704=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit705=== CONT TestPush_CompleteCommitsEveryRoot706=== CONT TestCreatePendingClosureRejectsOversizedNAR707=== RUN TestIsValidUploadKey/narinfo708=== PAUSE TestProxyWriteTimeout/1_GiB_nar709=== CONT TestPush_OverlappingRootsStoreOneRowPerKey710--- PASS: TestSkippedUploadsHandler (0.01s)711=== CONT TestReadRedirectUsesPublicS3URL712=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info713=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal714=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal715=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key716=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key717=== RUN TestProxyWriteTimeout/10_GiB_nar718=== PAUSE TestProxyWriteTimeout/10_GiB_nar719=== RUN TestProxyWriteTimeout/unknown_size720=== PAUSE TestProxyWriteTimeout/unknown_size721=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key722=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key723=== CONT TestGCSweepSkipsPendingObjects724=== PAUSE TestIsValidUploadKey/narinfo725=== RUN TestIsValidUploadKey/nar_zst726=== PAUSE TestIsValidUploadKey/nar_zst727=== RUN TestIsValidUploadKey/nar_xz728=== PAUSE TestIsValidUploadKey/nar_xz729=== RUN TestIsValidUploadKey/nar_plain730=== PAUSE TestIsValidUploadKey/nar_plain731=== RUN TestIsValidUploadKey/listing732=== CONT TestCacheConfigHandlerMaxNarSize7332026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures734=== PAUSE TestIsValidUploadKey/listing735=== CONT TestService_readinessHandler736--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)737--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)738=== CONT TestGenerateLandingPage739=== RUN TestIsValidUploadKey/build_log740=== PAUSE TestIsValidUploadKey/build_log741=== RUN TestIsValidUploadKey/build_log_home-manager_file742=== PAUSE TestIsValidUploadKey/build_log_home-manager_file743=== RUN TestIsValidUploadKey/build_log_plus_in_name744=== PAUSE TestIsValidUploadKey/build_log_plus_in_name745=== RUN TestIsValidUploadKey/build_log_question_mark746=== PAUSE TestIsValidUploadKey/build_log_question_mark747=== RUN TestIsValidUploadKey/build_log_equals748=== PAUSE TestIsValidUploadKey/build_log_equals749=== RUN TestIsValidUploadKey/realisation750=== PAUSE TestIsValidUploadKey/realisation751=== RUN TestIsValidUploadKey/realisation_plus_in_output752=== PAUSE TestIsValidUploadKey/realisation_plus_in_output753=== RUN TestIsValidUploadKey/nix-cache-info754=== PAUSE TestIsValidUploadKey/nix-cache-info755=== RUN TestIsValidUploadKey/index.html756=== PAUSE TestIsValidUploadKey/index.html757=== RUN TestIsValidUploadKey/narinfo_key,_nar_type758=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type759=== RUN TestIsValidUploadKey/nar_key,_narinfo_type760=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type761=== RUN TestIsValidUploadKey/listing_key,_narinfo_type762=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type763=== RUN TestIsValidUploadKey/traversal764=== PAUSE TestIsValidUploadKey/traversal765=== RUN TestIsValidUploadKey/traversal_nar766=== PAUSE TestIsValidUploadKey/traversal_nar767=== RUN TestIsValidUploadKey/absolute768=== PAUSE TestIsValidUploadKey/absolute769=== RUN TestIsValidUploadKey/empty_key770=== PAUSE TestIsValidUploadKey/empty_key771=== RUN TestIsValidUploadKey/unknown_type772=== PAUSE TestIsValidUploadKey/unknown_type773=== CONT TestService_healthCheckHandler774--- PASS: TestGenerateLandingPage (0.00s)775=== CONT TestGracefulShutdownDrainsInflight7762026/10/01 08:35:25 INFO Starting HTTP server address=127.0.0.1:459977772026/10/01 08:35:25 INFO Shutdown signal received, draining in-flight requests timeout=10s7782026-10-01 08:35:25.797 UTC [638] ERROR: relation "goose_db_version" does not exist at character 367792026-10-01 08:35:25.797 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026-10-01 08:35:25.803 UTC [639] ERROR: relation "goose_db_version" does not exist at character 367812026-10-01 08:35:25.803 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7822026-10-01 08:35:25.808 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367832026-10-01 08:35:25.808 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC784--- PASS: TestGracefulShutdownDrainsInflight (0.07s)785=== CONT TestGCTaskStore_Fail786--- PASS: TestGCTaskStore_Fail (0.00s)787=== CONT TestGCTaskStore_PhaseUpdates788--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)789=== CONT TestGCTaskStore_CompletedAllowsNewTask790--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)791=== CONT TestGCTaskStore_GetReturnsLatest792--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)793=== CONT TestGCTaskStore_GetEmpty794--- PASS: TestGCTaskStore_GetEmpty (0.00s)795=== CONT TestGCTaskStore_ConflictDifferentParams796--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)797=== CONT TestGCTaskStore_DeduplicateSameParams798--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)799=== CONT TestGCTaskStore_StartNew800--- PASS: TestGCTaskStore_StartNew (0.00s)801=== CONT TestCommitRacingPendingCleanupKeepsObjects802=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure803=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure804=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart805=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart806=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts807=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts808=== CONT TestPushWaitsForSweepHoldingRow8092026-10-01 08:35:25.833 UTC [644] ERROR: relation "goose_db_version" does not exist at character 368102026-10-01 08:35:25.833 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026-10-01 08:35:25.847 UTC [648] ERROR: relation "goose_db_version" does not exist at character 368122026-10-01 08:35:25.847 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026/10/01 08:35:25 OK 20241026095416_initial_model.sql (25.48ms)8142026/10/01 08:35:25 OK 20241026095416_initial_model.sql (28.84ms)8152026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)8162026-10-01 08:35:25.867 UTC [649] ERROR: relation "goose_db_version" does not exist at character 368172026-10-01 08:35:25.867 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (14.93ms)8192026/10/01 08:35:25 OK 20251218171726_add_pins.sql (17.13ms)8202026/10/01 08:35:25 OK 20241026095416_initial_model.sql (36.58ms)8212026/10/01 08:35:25 OK 20241026095416_initial_model.sql (41.71ms)8222026/10/01 08:35:25 OK 20251218171726_add_pins.sql (9.93ms)8232026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (7.17ms)8242026/10/01 08:35:25 OK 20241026095416_initial_model.sql (26.01ms)8252026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)8262026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)8272026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)8282026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)8292026/10/01 08:35:25 OK 20260905000000_add_claims.sql (5.48ms)8302026/10/01 08:35:25 OK 20251218171726_add_pins.sql (7.07ms)8312026-10-01 08:35:25.896 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368322026-10-01 08:35:25.896 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.83ms)8342026/10/01 08:35:25 OK 20251218171726_add_pins.sql (8.85ms)8352026/10/01 08:35:25 OK 20251218171726_add_pins.sql (6.17ms)8362026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (4.2ms)8372026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.71ms)8382026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (4.15ms)8392026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200008402026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (4.73ms)8412026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200008422026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (8.6ms)8432026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (8.74ms)8442026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (10.5ms)8452026/10/01 08:35:25 OK 1_commit_pending_closure.sql (5.05ms)8462026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.61ms)8472026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.37ms)8482026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.63ms)8492026/10/01 08:35:25 OK 3_commit_push.sql (2.45ms)8502026/10/01 08:35:25 goose: up to current file version: 38512026/10/01 08:35:25 OK 20260905000000_add_claims.sql (6.42ms)8522026/10/01 08:35:25 OK 20241026095416_initial_model.sql (24.26ms)8532026/10/01 08:35:25 OK 20260905000000_add_claims.sql (6.67ms)8542026/10/01 08:35:25 OK 2_object_stats_trigger.sql (3.22ms)8552026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.81ms)8562026/10/01 08:35:25 OK 3_commit_push.sql (2.08ms)8572026/10/01 08:35:25 goose: up to current file version: 38582026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12.24ms)8592026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (3.17ms)8602026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200008612026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (4.88ms)8622026-10-01 08:35:25.918 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368632026-10-01 08:35:25.918 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8642026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (5.18ms)8652026-10-01 08:35:25.918 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368662026-10-01 08:35:25.918 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8672026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)8682026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)8692026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (4.94ms)8702026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200008712026/10/01 08:35:25 OK 1_commit_pending_closure.sql (5.17ms)8722026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (5.11ms)8732026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200008742026-10-01 08:35:25.924 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368752026-10-01 08:35:25.924 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8762026/10/01 08:35:25 OK 20251218171726_add_pins.sql (14.98ms)8772026/10/01 08:35:25 OK 2_object_stats_trigger.sql (14.24ms)8782026/10/01 08:35:25 OK 1_commit_pending_closure.sql (14.39ms)8792026/10/01 08:35:25 OK 1_commit_pending_closure.sql (14.18ms)8802026/10/01 08:35:25 OK 3_commit_push.sql (3.78ms)8812026/10/01 08:35:25 goose: up to current file version: 38822026/10/01 08:35:25 OK 2_object_stats_trigger.sql (3.88ms)8832026/10/01 08:35:25 OK 2_object_stats_trigger.sql (3.76ms)8842026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (9.1ms)8852026/10/01 08:35:25 OK 20251218171726_add_pins.sql (22.49ms)8862026/10/01 08:35:25 OK 3_commit_push.sql (4.6ms)8872026/10/01 08:35:25 goose: up to current file version: 38882026/10/01 08:35:25 OK 3_commit_push.sql (4.75ms)8892026/10/01 08:35:25 goose: up to current file version: 3890--- PASS: TestReadProxyRangeRequest (0.31s)891=== CONT TestSweepRechecksPendingAfterLocking8922026/10/01 08:35:25 OK 20260905000000_add_claims.sql (5.04ms)8932026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12.47ms)8942026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12.66ms)8952026-10-01 08:35:25.953 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368962026-10-01 08:35:25.953 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (4.01ms)8982026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (9.68ms)8992026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)9002026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)9012026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (3.58ms)9022026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200009032026-10-01 08:35:25.957 UTC [656] ERROR: relation "goose_db_version" does not exist at character 369042026-10-01 08:35:25.957 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9052026/10/01 08:35:25 OK 20251218171726_add_pins.sql (5.12ms)9062026/10/01 08:35:25 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"9072026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.3ms)908--- PASS: TestService_AuthMiddleware (0.32s)909=== CONT TestGetExistingObjectsLocksRows9102026/10/01 08:35:25 OK 20251218171726_add_pins.sql (6.08ms)9112026/10/01 08:35:25 OK 20260905000000_add_claims.sql (7.79ms)9122026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.53ms)9132026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)9142026/10/01 08:35:25 OK 20241026095416_initial_model.sql (16.84ms)9152026/10/01 08:35:25 OK 3_commit_push.sql (2.35ms)9162026/10/01 08:35:25 goose: up to current file version: 39172026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (4.98ms)9182026-10-01 08:35:25.972 UTC [660] ERROR: relation "goose_db_version" does not exist at character 369192026-10-01 08:35:25.972 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9202026-10-01 08:35:25.973 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369212026-10-01 08:35:25.973 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (16.43ms)9232026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures9242026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures9262026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (14.24ms)9272026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200009282026/10/01 08:35:25 OK 20260905000000_add_claims.sql (16.94ms)9292026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (17ms)9302026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.87ms)9312026/10/01 08:35:25 OK 20260905000000_add_claims.sql (9.63ms)9322026/10/01 08:35:25 OK 1_commit_pending_closure.sql (5.44ms)9332026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (3.82ms)9342026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200009352026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.39ms)9362026/10/01 08:35:25 OK 20251218171726_add_pins.sql (8.04ms)9372026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.37ms)9382026/10/01 08:35:25 OK 20241026095416_initial_model.sql (23.58ms)9392026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.59ms)9402026/10/01 08:35:25 OK 3_commit_push.sql (2.47ms)9412026/10/01 08:35:25 goose: up to current file version: 39422026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.44ms)9432026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (4.32ms)9442026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200009452026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)9462026-10-01 08:35:25.996 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369472026-10-01 08:35:25.996 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9482026/10/01 08:35:25 OK 3_commit_push.sql (2.28ms)9492026/10/01 08:35:25 goose: up to current file version: 39502026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (8.28ms)9512026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.96ms)9522026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.99ms)9532026/10/01 08:35:26 OK 20241026095416_initial_model.sql (16.31ms)9542026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.34ms)9552026/10/01 08:35:26 OK 3_commit_push.sql (2.05ms)9562026/10/01 08:35:26 goose: up to current file version: 39572026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)9582026/10/01 08:35:26 OK 20260905000000_add_claims.sql (5.78ms)9592026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures9602026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (5.64ms)9612026-10-01 08:35:26.006 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369622026-10-01 08:35:26.006 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9632026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.88ms)9642026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (4.39ms)9652026-10-01 08:35:26.009 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369662026-10-01 08:35:26.009 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.87ms)9682026-10-01 08:35:26.009 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369692026-10-01 08:35:26.009 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9702026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.83ms)9712026/10/01 08:35:26 OK 20260905000000_add_claims.sql (5.01ms)9722026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)9732026-10-01 08:35:26.012 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369742026-10-01 08:35:26.012 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9752026-10-01 08:35:26.012 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369762026-10-01 08:35:26.012 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9772026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (3.89ms)9782026/10/01 08:35:26 goose: successfully migrated database to version: 202609231200009792026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (3.55ms)9802026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.91ms)9812026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.5ms)9822026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (5.77ms)9832026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.63ms)9842026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)9852026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.19ms)9862026/10/01 08:35:26 goose: successfully migrated database to version: 202609231200009872026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.1ms)9882026-10-01 08:35:26.018 UTC [669] ERROR: relation "goose_db_version" does not exist at character 369892026-10-01 08:35:26.018 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9902026/10/01 08:35:26 OK 1_commit_pending_closure.sql (5.49ms)9912026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.04ms)9922026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.53ms)9932026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)9942026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.87ms)9952026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.73ms)9962026-10-01 08:35:26.022 UTC [670] ERROR: relation "goose_db_version" does not exist at character 369972026-10-01 08:35:26.022 UTC [670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.77ms)9992026-10-01 08:35:26.023 UTC [671] ERROR: relation "goose_db_version" does not exist at character 3610002026-10-01 08:35:26.023 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10012026/10/01 08:35:26 OK 3_commit_push.sql (1.99ms)10022026/10/01 08:35:26 goose: up to current file version: 310032026/10/01 08:35:26 OK 2_object_stats_trigger.sql (3.21ms)10042026-10-01 08:35:26.025 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3610052026-10-01 08:35:26.025 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10062026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (7.26ms)10072026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)10082026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.89ms)10092026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010102026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.84ms)10112026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.72ms)10122026/10/01 08:35:26 OK 3_commit_push.sql (2.26ms)10132026/10/01 08:35:26 goose: up to current file version: 310142026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)10152026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.18ms)10162026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.55ms)10172026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.44ms)10182026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.83ms)10192026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.85ms)10202026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.73ms)10212026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.04ms)10222026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)10232026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)10242026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.64ms)10252026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.74ms)10262026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.22ms)10272026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010282026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.8ms)10292026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.46ms)10302026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.84ms)10312026/10/01 08:35:26 OK 3_commit_push.sql (1.48ms)10322026/10/01 08:35:26 goose: up to current file version: 310332026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.16ms)10342026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010352026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (3.17ms)10362026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010372026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)10382026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)10392026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.1ms)10402026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.61ms)10412026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.74ms)10422026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.4ms)10432026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)10442026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10452026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.74ms)10462026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.13ms)10472026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.81ms)10482026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.7ms)10492026/10/01 08:35:26 OK 3_commit_push.sql (2.09ms)10502026/10/01 08:35:26 goose: up to current file version: 310512026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)10522026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.58ms)10532026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.57ms)10542026/10/01 08:35:26 OK 3_commit_push.sql (1.93ms)10552026/10/01 08:35:26 goose: up to current file version: 310562026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.11ms)10572026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.96ms)10582026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.93ms)10592026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.72ms)10602026/10/01 08:35:26 OK 20241026095416_initial_model.sql (14.94ms)10612026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.64ms)10622026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)10632026/10/01 08:35:26 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1064--- PASS: TestCompleteMultipartUnregistered (0.41s)1065=== CONT TestRegisterCompletedObjectNeedsPendingRow10662026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (15.78ms)10672026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (13.4ms)10682026/10/01 08:35:26 OK 3_commit_push.sql (12.85ms)10692026/10/01 08:35:26 goose: up to current file version: 310702026/10/01 08:35:26 OK 20260905000000_add_claims.sql (14.82ms)10712026/10/01 08:35:26 OK 20260905000000_add_claims.sql (14.07ms)10722026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (13.43ms)10732026/10/01 08:35:26 OK 20251218171726_add_pins.sql (12.43ms)10742026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (14.66ms)10752026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (13.55ms)10762026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (13.36ms)10772026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.67ms)10782026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010792026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.8ms)10802026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.99ms)10812026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.81ms)10822026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.55ms)10832026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.64ms)10842026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.53ms)10852026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.68ms)10862026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.85ms)10872026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.74ms)10882026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (3.19ms)10892026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010902026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.97ms)10912026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000010922026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.48ms)10932026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.73ms)10942026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.91ms)10952026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)10962026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.11ms)10972026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.28ms)10982026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.59ms)10992026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011002026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.77ms)11012026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)11022026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.77ms)11032026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011042026/10/01 08:35:26 OK 3_commit_push.sql (2.13ms)11052026/10/01 08:35:26 goose: up to current file version: 311062026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.1ms)11072026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.02ms)11082026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.15ms)11092026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (6.18ms)11102026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.06ms)11112026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.58ms)11122026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.73ms)11132026/10/01 08:35:26 OK 3_commit_push.sql (1.87ms)11142026/10/01 08:35:26 goose: up to current file version: 311152026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.07ms)11162026/10/01 08:35:26 OK 3_commit_push.sql (2ms)11172026/10/01 08:35:26 goose: up to current file version: 311182026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.86ms)11192026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.91ms)1120--- PASS: TestService_Rustfstest (0.43s)1121=== CONT TestSweepSkipsRowsLockedByPush11222026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.58ms)11232026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (3.12ms)11242026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011252026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.58ms)11262026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.69ms)11272026/10/01 08:35:26 OK 3_commit_push.sql (1.81ms)11282026/10/01 08:35:26 goose: up to current file version: 311292026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.97ms)11302026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011312026/10/01 08:35:26 OK 3_commit_push.sql (882.69µs)11322026/10/01 08:35:26 goose: up to current file version: 311332026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.69ms)11342026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011352026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.44ms)11362026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.73ms)11372026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.92ms)11382026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.74ms)11392026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.91ms)11402026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.05ms)11412026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.91ms)11422026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011432026-10-01 08:35:26.080 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3611442026-10-01 08:35:26.080 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026/10/01 08:35:26 OK 3_commit_push.sql (1.85ms)11462026/10/01 08:35:26 goose: up to current file version: 311472026/10/01 08:35:26 OK 3_commit_push.sql (2.15ms)11482026/10/01 08:35:26 goose: up to current file version: 311492026/10/01 08:35:26 OK 2_object_stats_trigger.sql (3.23ms)11502026/10/01 08:35:26 OK 3_commit_push.sql (1.22ms)11512026/10/01 08:35:26 goose: up to current file version: 311522026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.67ms)11532026/10/01 08:35:26 OK 2_object_stats_trigger.sql (3.09ms)11542026/10/01 08:35:26 OK 3_commit_push.sql (1.68ms)11552026/10/01 08:35:26 goose: up to current file version: 311562026-10-01 08:35:26.094 UTC [678] ERROR: relation "goose_db_version" does not exist at character 3611572026-10-01 08:35:26.094 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11582026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.5ms)11592026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)11602026/10/01 08:35:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11612026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.94ms)11622026/10/01 08:35:26 INFO Aborted multipart uploads count=011632026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)11642026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.24ms)11652026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures11662026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)11672026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.78ms)11682026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.29ms)11692026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.35ms)11702026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.84ms)11712026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011722026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)11732026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.52ms)11742026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.69ms)11752026/10/01 08:35:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11762026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.53ms)11772026/10/01 08:35:26 OK 3_commit_push.sql (1.38ms)11782026/10/01 08:35:26 goose: up to current file version: 311792026/10/01 08:35:26 INFO Aborted multipart uploads count=111802026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.7ms)11812026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.12ms)11822026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000011832026/10/01 08:35:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11842026-10-01 08:35:26.129 UTC [649] ERROR: Closure does not exist: id=111852026-10-01 08:35:26.129 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11862026-10-01 08:35:26.129 UTC [649] STATEMENT: -- name: CommitPendingClosure :exec1187 SELECT commit_pending_closure($1::bigint)1188 1189--- PASS: TestService_cleanupPendingClosuresHandler (0.49s)1190=== CONT TestFailedS3DeleteKeepsTombstone11912026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.28ms)11922026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures11932026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.45ms)11942026/10/01 08:35:26 OK 3_commit_push.sql (1.28ms)11952026/10/01 08:35:26 goose: up to current file version: 311962026-10-01 08:35:26.149 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3611972026-10-01 08:35:26.149 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11982026/10/01 08:35:26 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11992026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures1200--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.52s)1201=== CONT TestForceGCDuringPushOffersSweptObject1202=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1203=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows12042026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures1205=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1206=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1207=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12082026-10-01 08:35:26.166 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3612092026-10-01 08:35:26.166 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12102026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.08ms)12112026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)12122026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.84ms)12132026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)12142026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.48ms)12152026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2ms)12162026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.46ms)12172026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.36ms)12182026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.94ms)12192026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (12.2ms)12212026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000012222026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (14.96ms)12232026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.5ms)12242026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.83ms)12252026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.78ms)12262026/10/01 08:35:26 OK 3_commit_push.sql (1.71ms)12272026/10/01 08:35:26 goose: up to current file version: 312282026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.83ms)12292026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.05ms)12302026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000012312026/10/01 08:35:26 OK 1_commit_pending_closure.sql (1.83ms)12322026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.41ms)12332026/10/01 08:35:26 OK 3_commit_push.sql (1.32ms)12342026/10/01 08:35:26 goose: up to current file version: 312352026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures12362026-10-01 08:35:26.230 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3612372026-10-01 08:35:26.230 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1238--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.60s)1239=== CONT TestGCSweepDeliversEachKeyOnce12402026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.31ms)12412026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)12422026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.44ms)12432026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures12442026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)12452026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.12ms)12462026-10-01 08:35:26.256 UTC [689] ERROR: relation "goose_db_version" does not exist at character 3612472026-10-01 08:35:26.256 UTC [689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.07ms)12492026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.99ms)12502026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000012512026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.47ms)12522026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.45ms)12532026/10/01 08:35:26 OK 3_commit_push.sql (1.45ms)12542026/10/01 08:35:26 goose: up to current file version: 312552026/10/01 08:35:26 OK 20241026095416_initial_model.sql (7.68ms)12562026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)12572026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12582026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.94ms)12592026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)12602026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.69ms)12612026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures12622026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.59ms)12632026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.05ms)12642026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000012652026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.82ms)12662026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.2ms)12672026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12682026/10/01 08:35:26 OK 3_commit_push.sql (1.52ms)12692026/10/01 08:35:26 goose: up to current file version: 312702026/10/01 08:35:26 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDIxYmVkMzctMGY4Ni00YmEzLTg5OWQtZjA4YjFiMWY0ZTFjLmNmYjZkMjQzLWM5MjgtNDI4ZC05OTRiLWFlY2Y5MTA0Njc2ZHgxNzkwODQzNzI2MjYyNjgzMTk312712026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures12722026/10/01 08:35:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDIxYmVkMzctMGY4Ni00YmEzLTg5OWQtZjA4YjFiMWY0ZTFjLmNmYjZkMjQzLWM5MjgtNDI4ZC05OTRiLWFlY2Y5MTA0Njc2ZHgxNzkwODQzNzI2MjYyNjgzMTk3 parts=11273--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.66s)1274=== CONT TestTombstonedObjectOfferedWithoutWaiting12752026-10-01 08:35:26.325 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3612762026-10-01 08:35:26.325 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1277--- PASS: TestReadRedirectUsesPublicS3URL (0.59s)1278=== CONT TestIsValidCachePath1279=== RUN TestIsValidCachePath/narinfo1280=== PAUSE TestIsValidCachePath/narinfo1281=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1282=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1283=== RUN TestIsValidCachePath/nar_zst1284=== PAUSE TestIsValidCachePath/nar_zst1285=== RUN TestIsValidCachePath/nar_xz1286=== PAUSE TestIsValidCachePath/nar_xz1287=== RUN TestIsValidCachePath/nar_bz21288=== PAUSE TestIsValidCachePath/nar_bz21289=== RUN TestIsValidCachePath/nar_uncompressed1290=== PAUSE TestIsValidCachePath/nar_uncompressed1291=== RUN TestIsValidCachePath/ls1292=== PAUSE TestIsValidCachePath/ls1293=== RUN TestIsValidCachePath/log1294=== PAUSE TestIsValidCachePath/log1295=== RUN TestIsValidCachePath/realisation1296=== PAUSE TestIsValidCachePath/realisation1297=== RUN TestIsValidCachePath/nix-cache-info1298=== PAUSE TestIsValidCachePath/nix-cache-info1299=== RUN TestIsValidCachePath/index.html1300=== PAUSE TestIsValidCachePath/index.html1301=== RUN TestIsValidCachePath/traversal_parent1302=== PAUSE TestIsValidCachePath/traversal_parent1303=== RUN TestIsValidCachePath/traversal_in_middle1304=== PAUSE TestIsValidCachePath/traversal_in_middle1305=== RUN TestIsValidCachePath/invalid_char_e1306=== PAUSE TestIsValidCachePath/invalid_char_e1307=== RUN TestIsValidCachePath/invalid_char_u1308=== PAUSE TestIsValidCachePath/invalid_char_u1309=== RUN TestIsValidCachePath/random_path1310=== PAUSE TestIsValidCachePath/random_path1311=== RUN TestIsValidCachePath/empty1312=== PAUSE TestIsValidCachePath/empty1313=== RUN TestIsValidCachePath/leading_slash1314=== PAUSE TestIsValidCachePath/leading_slash1315=== RUN TestIsValidCachePath/wrong_extension1316=== PAUSE TestIsValidCachePath/wrong_extension1317=== RUN TestIsValidCachePath/short_hash1318=== PAUSE TestIsValidCachePath/short_hash1319=== CONT TestReadRedirectKeepsNarinfoProxied13202026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes13212026/10/01 08:35:26 OK 20241026095416_initial_model.sql (7.91ms)13222026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)13232026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.39ms)13242026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)13252026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.25ms)13262026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.53ms)13272026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.93ms)13282026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000013292026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.31ms)13302026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.38ms)13312026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/1/complete13322026/10/01 08:35:26 OK 3_commit_push.sql (1.41ms)13332026/10/01 08:35:26 goose: up to current file version: 313342026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes1335--- PASS: TestPush_CompleteCommitsEveryRoot (0.64s)1336=== CONT TestReadRedirectNar13372026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes13382026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13392026/10/01 08:35:26 INFO Signed narinfos id=1 count=11340--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.66s)1341=== CONT TestReadProxyDisabled13422026-10-01 08:35:26.409 UTC [702] ERROR: relation "goose_db_version" does not exist at character 3613432026-10-01 08:35:26.409 UTC [702] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13442026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/1/complete1345--- PASS: TestService_healthCheckHandler (0.68s)1346=== CONT TestReadProxyRootRedirectsToIndexHTML13472026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.48ms)13482026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes13492026-10-01 08:35:26.427 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3613502026-10-01 08:35:26.427 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13512026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)13522026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.78ms)13532026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)13542026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.54ms)13552026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.76ms)13562026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.52ms)13572026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)13582026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.28ms)13592026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000013602026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.21ms)13612026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.65ms)13622026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.78ms)13632026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)1364=== RUN TestPush_RejectsBadRequests/no_roots1365=== PAUSE TestPush_RejectsBadRequests/no_roots1366=== RUN TestPush_RejectsBadRequests/no_objects1367=== PAUSE TestPush_RejectsBadRequests/no_objects1368=== RUN TestPush_RejectsBadRequests/bad_root1369=== PAUSE TestPush_RejectsBadRequests/bad_root1370=== RUN TestPush_RejectsBadRequests/root_not_in_objects1371=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1372=== CONT TestReadProxyConditionalGet13732026/10/01 08:35:26 OK 3_commit_push.sql (1.69ms)13742026/10/01 08:35:26 goose: up to current file version: 313752026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13762026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.24ms)13772026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.48ms)13782026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.29ms)13792026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000013802026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.41ms)13812026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.71ms)13822026/10/01 08:35:26 OK 3_commit_push.sql (1.37ms)13832026/10/01 08:35:26 goose: up to current file version: 313842026/10/01 08:35:26 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDIxYmVkMzctMGY4Ni00YmEzLTg5OWQtZjA4YjFiMWY0ZTFjLjliNTIzYjc1LWQ2MWYtNDE1YS05ZTUxLWJmMTA1NDkwOWM2YngxNzkwODQzNzI1OTk3NTczMjg1 parts=1013852026/10/01 08:35:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13862026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes13872026-10-01 08:35:26.482 UTC [722] ERROR: relation "goose_db_version" does not exist at character 3613882026-10-01 08:35:26.482 UTC [722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13892026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13902026/10/01 08:35:26 INFO Completed upload id=113912026/10/01 08:35:26 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013922026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures13932026/10/01 08:35:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures13942026/10/01 08:35:26 INFO Aborted multipart uploads count=013952026/10/01 08:35:26 INFO Aborted multipart uploads count=013962026/10/01 08:35:26 OK 20241026095416_initial_model.sql (18.72ms)13972026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period13982026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)1399--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.78s)1400=== CONT TestReadProxyHead14012026/10/01 08:35:26 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=014022026/10/01 08:35:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDIxYmVkMzctMGY4Ni00YmEzLTg5OWQtZjA4YjFiMWY0ZTFjLmZkN2RhOTFjLTVlZjgtNDlhNy1iN2FjLTU1N2EwNDRiNWQwNHgxNzkwODQzNzI2MDE3MzY3MjY4 parts=1014032026/10/01 08:35:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14042026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.75ms)14052026/10/01 08:35:26 INFO Vacuumed table table=pending_closures14062026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)14072026/10/01 08:35:26 INFO Completed upload id=114082026/10/01 08:35:26 INFO Vacuumed table table=pending_objects14092026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures14102026/10/01 08:35:26 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=014112026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.39ms)14122026-10-01 08:35:26.520 UTC [728] ERROR: relation "goose_db_version" does not exist at character 3614132026-10-01 08:35:26.520 UTC [728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14142026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.21ms)14152026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads14162026/10/01 08:35:26 INFO Vacuumed table table=pending_closures14172026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures14182026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.48ms)14192026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000014202026/10/01 08:35:26 INFO Vacuumed table table=pending_objects14212026/10/01 08:35:26 INFO Vacuumed table table=closures14222026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.85ms)14232026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads14242026/10/01 08:35:26 INFO Vacuumed table table=objects14252026/10/01 08:35:26 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14262026/10/01 08:35:26 WARN Found objects in DB but missing from S3, will re-upload count=11427--- PASS: TestService_verifyS3Integrity (0.89s)1428=== CONT TestReadProxyInvalidPath14292026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.37ms)14302026/10/01 08:35:26 INFO Vacuumed table table=closures14312026/10/01 08:35:26 OK 3_commit_push.sql (2.28ms)14322026/10/01 08:35:26 goose: up to current file version: 314332026-10-01 08:35:26.532 UTC [730] ERROR: relation "goose_db_version" does not exist at character 3614342026-10-01 08:35:26.532 UTC [730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026/10/01 08:35:26 INFO Vacuumed table table=objects14362026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.57ms)14372026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/2/complete14382026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)14392026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.74ms)14402026/10/01 08:35:26 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001441--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.81s)1442=== CONT TestReadProxy4041443--- PASS: TestService_createPendingClosureHandler (0.90s)1444=== CONT TestReadProxyNarStreaming14452026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)14462026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures14472026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9ms)14482026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.34ms)14492026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)14502026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.67ms)14512026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.15ms)14522026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.89ms)14532026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000014542026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.51ms)14552026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)14562026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.79ms)14572026-10-01 08:35:26.559 UTC [740] ERROR: relation "goose_db_version" does not exist at character 3614582026-10-01 08:35:26.559 UTC [740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14592026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.01ms)14602026/10/01 08:35:26 OK 3_commit_push.sql (2.06ms)14612026/10/01 08:35:26 goose: up to current file version: 314622026/10/01 08:35:26 INFO Aborted multipart uploads count=014632026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.63ms)14642026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period14652026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.21ms)14662026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000014672026/10/01 08:35:26 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=014682026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.75ms)14692026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.02ms)14702026/10/01 08:35:26 WARN readiness check failed error="closed pool"1471--- PASS: TestService_readinessHandler (0.83s)1472=== CONT TestReadProxyNarinfoAlreadyDecompressed14732026/10/01 08:35:26 INFO Vacuumed table table=pending_closures14742026/10/01 08:35:26 OK 3_commit_push.sql (2.88ms)14752026/10/01 08:35:26 goose: up to current file version: 314762026/10/01 08:35:26 INFO Vacuumed table table=pending_objects14772026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads14782026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.49ms)14792026/10/01 08:35:26 INFO Vacuumed table table=closures14802026/10/01 08:35:26 INFO Vacuumed table table=objects14812026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)14822026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.91ms)1483--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.78s)1484=== CONT TestReadProxyNarinfo14852026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)14862026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.98ms)14872026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.04ms)14882026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (14.8ms)14892026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000014902026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures14912026/10/01 08:35:26 OK 1_commit_pending_closure.sql (6.06ms)14922026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2ms)14932026/10/01 08:35:26 OK 3_commit_push.sql (2.05ms)14942026/10/01 08:35:26 goose: up to current file version: 314952026-10-01 08:35:26.646 UTC [746] ERROR: relation "goose_db_version" does not exist at character 3614962026-10-01 08:35:26.646 UTC [746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14972026/10/01 08:35:26 INFO Aborted multipart uploads count=014982026-10-01 08:35:26.652 UTC [748] ERROR: relation "goose_db_version" does not exist at character 3614992026-10-01 08:35:26.652 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15002026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period15012026/10/01 08:35:26 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=015022026/10/01 08:35:26 INFO Vacuumed table table=pending_closures15032026/10/01 08:35:26 INFO Aborted multipart uploads count=015042026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.31ms)15052026/10/01 08:35:26 INFO Vacuumed table table=pending_objects15062026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads15072026/10/01 08:35:26 INFO Vacuumed table table=closures15082026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)15092026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period15102026/10/01 08:35:26 INFO Vacuumed table table=objects15112026-10-01 08:35:26.670 UTC [750] ERROR: relation "goose_db_version" does not exist at character 3615122026-10-01 08:35:26.670 UTC [750] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15132026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.1ms)15142026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.12ms)15152026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)15162026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)15172026-10-01 08:35:26.678 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3615182026-10-01 08:35:26.678 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15192026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.7ms)15202026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.61ms)1521--- PASS: TestGCSweepSkipsPendingObjects (0.95s)1522=== CONT TestClientWithDependencies15232026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.41ms)15242026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (6.79ms)15252026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000015262026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.02ms)15272026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (8.64ms)15282026/10/01 08:35:26 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=015292026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)15302026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.09ms)15312026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.75ms)15322026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.48ms)15332026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.46ms)15342026/10/01 08:35:26 INFO Vacuumed table table=pending_closures15352026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (1.54ms)15362026/10/01 08:35:26 OK 3_commit_push.sql (1.01ms)15372026/10/01 08:35:26 goose: up to current file version: 315382026/10/01 08:35:26 INFO Vacuumed table table=pending_objects1539--- PASS: TestGetExistingObjectsLocksRows (0.73s)1540=== CONT TestDeduplicatedObjectsRecordedAsPending15412026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads15422026/10/01 08:35:26 INFO Vacuumed table table=closures15432026-10-01 08:35:26.700 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3615442026-10-01 08:35:26.700 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15452026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (9.5ms)15462026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000015472026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (11.87ms)15482026/10/01 08:35:26 OK 20241026095416_initial_model.sql (15.33ms)15492026/10/01 08:35:26 INFO Vacuumed table table=objects15502026/10/01 08:35:26 OK 1_commit_pending_closure.sql (1.82ms)15512026/10/01 08:35:26 OK 2_object_stats_trigger.sql (881.55µs)15522026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)1553--- PASS: TestSweepRechecksPendingAfterLocking (0.76s)15542026/10/01 08:35:26 OK 3_commit_push.sql (1.02ms)1555=== CONT TestPushDedupSurvivesConcurrentGC15562026/10/01 08:35:26 goose: up to current file version: 315572026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.72ms)15582026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.06ms)15592026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.14ms)15602026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.17ms)15612026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000015622026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)1563--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.67s)1564=== CONT TestGCMetrics15652026-10-01 08:35:26.715 UTC [759] ERROR: relation "goose_db_version" does not exist at character 3615662026-10-01 08:35:26.715 UTC [759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15672026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.69ms)15682026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.67ms)15692026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)15702026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.54ms)15712026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.85ms)15722026/10/01 08:35:26 OK 3_commit_push.sql (2.05ms)15732026/10/01 08:35:26 goose: up to current file version: 315742026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.12ms)15752026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.81ms)15762026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.3ms)15772026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000015782026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)15792026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.45ms)15802026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.54ms)15812026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15822026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.93ms)15832026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.78ms)15842026/10/01 08:35:26 OK 3_commit_push.sql (2.39ms)15852026/10/01 08:35:26 goose: up to current file version: 315862026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.03ms)15872026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.22ms)15882026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000015892026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)15902026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.31ms)15912026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.62ms)15922026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.89ms)15932026/10/01 08:35:26 OK 3_commit_push.sql (2.03ms)15942026/10/01 08:35:26 goose: up to current file version: 315952026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)15962026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.36ms)15972026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.93ms)15982026/10/01 08:35:26 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDIxYmVkMzctMGY4Ni00YmEzLTg5OWQtZjA4YjFiMWY0ZTFjLjhjNDcyOTA4LTllN2QtNDAyYi04Mjc5LWU0Y2UwNzQ0OGM0NXgxNzkwODQzNzI2MjA3NTM1MTEy parts=1215992026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.84ms)16002026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000016012026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures16022026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.64ms)16032026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.55ms)1604--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.11s)1605=== CONT TestGCBugBareHashReferences16062026/10/01 08:35:26 OK 3_commit_push.sql (1.95ms)16072026/10/01 08:35:26 goose: up to current file version: 316082026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures16092026/10/01 08:35:26 INFO Aborted multipart uploads count=016102026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period16112026/10/01 08:35:26 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=016122026/10/01 08:35:26 INFO Vacuumed table table=pending_closures16132026/10/01 08:35:26 INFO Vacuumed table table=pending_objects16142026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads16152026/10/01 08:35:26 INFO Vacuumed table table=closures16162026/10/01 08:35:26 INFO Vacuumed table table=objects16172026/10/01 08:35:26 INFO Aborted multipart uploads count=016182026-10-01 08:35:26.789 UTC [771] ERROR: relation "goose_db_version" does not exist at character 3616192026-10-01 08:35:26.789 UTC [771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16202026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period16212026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16222026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures16232026/10/01 08:35:26 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=016242026/10/01 08:35:26 INFO Vacuumed table table=pending_closures16252026/10/01 08:35:26 INFO Vacuumed table table=pending_objects16262026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads16272026/10/01 08:35:26 INFO Vacuumed table table=closures16282026/10/01 08:35:26 INFO Vacuumed table table=objects1629--- PASS: TestSweepSkipsRowsLockedByPush (0.75s)1630=== CONT TestLeadEndsOnShutdown16312026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.74ms)16322026-10-01 08:35:26.819 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3616332026-10-01 08:35:26.819 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16342026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)16352026-10-01 08:35:26.822 UTC [773] ERROR: relation "goose_db_version" does not exist at character 3616362026-10-01 08:35:26.822 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16372026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.82ms)16382026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)16392026-10-01 08:35:26.831 UTC [776] ERROR: relation "goose_db_version" does not exist at character 3616402026-10-01 08:35:26.831 UTC [776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16412026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.36ms)16422026/10/01 08:35:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDIxYmVkMzctMGY4Ni00YmEzLTg5OWQtZjA4YjFiMWY0ZTFjLjdhY2JmMjdhLTM2MGMtNDZiZC1iMjhmLTQ0MTViODk5ZTZlMHgxNzkwODQzNzI2Mjk1MjU2NzEz parts=1216432026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.66ms)16442026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.89ms)1645--- PASS: TestRedundantMultipartUpload (1.10s)1646=== CONT TestLeadElectsOneAndHandsOver16472026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.42ms)16482026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)16492026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)16502026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (3.19ms)16512026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000016522026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.23ms)16532026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.03ms)16542026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.98ms)16552026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.08ms)16562026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.86ms)16572026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)16582026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)16592026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)16602026/10/01 08:35:26 OK 3_commit_push.sql (1.86ms)16612026/10/01 08:35:26 goose: up to current file version: 316622026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.03ms)16632026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.31ms)16642026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.3ms)16652026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.19ms)16662026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.7ms)16672026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.27ms)16682026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000016692026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.39ms)16702026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000016712026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)16722026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.35ms)16732026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.85ms)16742026/10/01 08:35:26 INFO Aborted multipart uploads count=016752026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures16762026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.91ms)16772026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.24ms)16782026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2ms)16792026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period16802026/10/01 08:35:26 OK 3_commit_push.sql (1.52ms)16812026/10/01 08:35:26 goose: up to current file version: 316822026/10/01 08:35:26 OK 3_commit_push.sql (889.92µs)16832026/10/01 08:35:26 goose: up to current file version: 316842026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.04ms)16852026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.2ms)16862026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000016872026/10/01 08:35:26 INFO Aborted multipart uploads count=016882026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.48ms)16892026-10-01 08:35:26.869 UTC [781] ERROR: relation "goose_db_version" does not exist at character 3616902026-10-01 08:35:26.869 UTC [781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16912026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period16922026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.41ms)1693--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.57s)1694=== CONT TestResolveDBConnectionString16952026/10/01 08:35:26 OK 3_commit_push.sql (1.35ms)16962026/10/01 08:35:26 goose: up to current file version: 31697=== RUN TestResolveDBConnectionString/flag_wins1698=== PAUSE TestResolveDBConnectionString/flag_wins1699=== RUN TestResolveDBConnectionString/file_when_flag_empty1700=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1701=== RUN TestResolveDBConnectionString/missing_file_is_an_error1702=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1703=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1704=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1705=== RUN TestResolveDBConnectionString/nothing_configured1706=== PAUSE TestResolveDBConnectionString/nothing_configured1707=== CONT TestClientFallsBackToClosures17082026/10/01 08:35:26 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17092026/10/01 08:35:26 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."17102026/10/01 08:35:26 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=01711--- PASS: TestFailedS3DeleteKeepsTombstone (0.75s)1712=== CONT TestClientPushesUseOnePush17132026/10/01 08:35:26 INFO Vacuumed table table=pending_closures17142026/10/01 08:35:26 INFO Vacuumed table table=pending_objects17152026/10/01 08:35:26 OK 20241026095416_initial_model.sql (8.35ms)17162026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads17172026/10/01 08:35:26 INFO Vacuumed table table=closures17182026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)17192026/10/01 08:35:26 INFO Vacuumed table table=objects17202026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.27ms)1721--- PASS: TestGCSweepDeliversEachKeyOnce (0.65s)1722=== CONT TestPinProtectsFromGC1723--- PASS: TestReadRedirectKeepsNarinfoProxied (0.56s)1724=== CONT TestClientSharedPathCommittedMidPush17252026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)17262026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.89ms)17272026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.4ms)17282026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.65ms)17292026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000017302026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.08ms)17312026-10-01 08:35:26.911 UTC [790] ERROR: relation "goose_db_version" does not exist at character 3617322026-10-01 08:35:26.911 UTC [790] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17332026/10/01 08:35:26 OK 2_object_stats_trigger.sql (10.85ms)17342026/10/01 08:35:26 OK 3_commit_push.sql (5.96ms)17352026/10/01 08:35:26 goose: up to current file version: 31736--- PASS: TestReadRedirectNar (0.55s)1737=== CONT TestCreatePin_ReservedPins17382026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.96ms)17392026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)17402026-10-01 08:35:26.933 UTC [791] ERROR: relation "goose_db_version" does not exist at character 3617412026-10-01 08:35:26.933 UTC [791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17422026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.01ms)17432026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)17442026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.45ms)1745--- PASS: TestReadProxyDisabled (0.54s)1746=== CONT TestProxyHeadersOnlyTrustedOnSocket17472026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.75ms)17482026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.54ms)17492026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000017502026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11ms)17512026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.64ms)17522026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)17532026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.96ms)17542026/10/01 08:35:26 OK 3_commit_push.sql (1.99ms)17552026/10/01 08:35:26 goose: up to current file version: 317562026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.1ms)17572026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)17582026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.87ms)17592026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.75ms)17602026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.37ms)17612026/10/01 08:35:26 goose: successfully migrated database to version: 202609231200001762--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.56s)1763=== CONT TestObjectStatsTrigger17642026/10/01 08:35:26 OK 1_commit_pending_closure.sql (11.43ms)17652026/10/01 08:35:26 OK 2_object_stats_trigger.sql (3.62ms)17662026/10/01 08:35:26 OK 3_commit_push.sql (1.44ms)17672026/10/01 08:35:26 goose: up to current file version: 317682026-10-01 08:35:26.996 UTC [796] ERROR: relation "goose_db_version" does not exist at character 3617692026-10-01 08:35:26.996 UTC [796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17702026/10/01 08:35:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43945/oidc17712026-10-01 08:35:26.998 UTC [797] ERROR: relation "goose_db_version" does not exist at character 3617722026-10-01 08:35:26.998 UTC [797] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17732026-10-01 08:35:26.998 UTC [798] ERROR: relation "goose_db_version" does not exist at character 3617742026-10-01 08:35:26.998 UTC [798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17752026-10-01 08:35:27.003 UTC [800] ERROR: relation "goose_db_version" does not exist at character 3617762026-10-01 08:35:27.003 UTC [800] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17772026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9ms)1778--- PASS: TestReadProxyConditionalGet (0.56s)1779=== CONT TestParseSingleRange1780=== RUN TestParseSingleRange/none1781=== PAUSE TestParseSingleRange/none1782=== RUN TestParseSingleRange/unknown_unit1783=== PAUSE TestParseSingleRange/unknown_unit1784=== RUN TestParseSingleRange/multi-range_ignored17852026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.52ms)1786=== PAUSE TestParseSingleRange/multi-range_ignored1787=== RUN TestParseSingleRange/malformed_no_dash1788=== PAUSE TestParseSingleRange/malformed_no_dash1789=== RUN TestParseSingleRange/malformed_both_empty1790=== PAUSE TestParseSingleRange/malformed_both_empty1791=== RUN TestParseSingleRange/malformed_end_before_start1792=== PAUSE TestParseSingleRange/malformed_end_before_start1793=== RUN TestParseSingleRange/closed1794=== PAUSE TestParseSingleRange/closed1795=== RUN TestParseSingleRange/open-ended1796=== PAUSE TestParseSingleRange/open-ended1797=== RUN TestParseSingleRange/end_clamped_to_size1798=== PAUSE TestParseSingleRange/end_clamped_to_size1799=== RUN TestParseSingleRange/suffix1800=== PAUSE TestParseSingleRange/suffix1801=== RUN TestParseSingleRange/suffix_exceeds_size1802=== PAUSE TestParseSingleRange/suffix_exceeds_size1803=== RUN TestParseSingleRange/single_byte18042026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)1805=== PAUSE TestParseSingleRange/single_byte1806=== RUN TestParseSingleRange/start_past_EOF1807=== PAUSE TestParseSingleRange/start_past_EOF1808=== RUN TestParseSingleRange/start_far_past_EOF1809=== PAUSE TestParseSingleRange/start_far_past_EOF1810=== CONT TestCacheConfigHandler1811=== RUN TestCacheConfigHandler/full_config,_no_issuer1812=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1813=== RUN TestCacheConfigHandler/no_cache_url_configured1814=== PAUSE TestCacheConfigHandler/no_cache_url_configured1815=== RUN TestCacheConfigHandler/no_signing_keys1816=== PAUSE TestCacheConfigHandler/no_signing_keys1817=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1818=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1819=== CONT TestClientMultipleUploads18202026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.46ms)18212026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)18222026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)18232026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.5ms)18242026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.6ms)18252026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.26ms)18262026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.39ms)18272026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)18282026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)18292026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (3.64ms)1830--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.86s)1831=== CONT TestOrphanedObjectsGCStressTest18322026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)18332026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.36ms)18342026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.44ms)18352026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.29ms)18362026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.44ms)18372026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.89ms)18382026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (3.61ms)18392026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)18402026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.51ms)18412026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000018422026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.45ms)18432026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.43ms)18442026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000018452026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.12ms)18462026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.61ms)18472026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000018482026/10/01 08:35:27 OK 1_commit_pending_closure.sql (3.18ms)18492026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.99ms)18502026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.34ms)18512026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.88ms)18522026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.39ms)1853--- PASS: TestReadProxyInvalidPath (0.51s)18542026/10/01 08:35:27 OK 1_commit_pending_closure.sql (3.41ms)1855=== CONT TestClientIntegration18562026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.64ms)18572026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000018582026/10/01 08:35:27 OK 3_commit_push.sql (2.02ms)18592026/10/01 08:35:27 goose: up to current file version: 318602026/10/01 08:35:27 OK 3_commit_push.sql (1.73ms)18612026/10/01 08:35:27 goose: up to current file version: 318622026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.52ms)18632026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.88ms)18642026-10-01 08:35:27.042 UTC [806] ERROR: relation "goose_db_version" does not exist at character 3618652026-10-01 08:35:27.042 UTC [806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18662026/10/01 08:35:27 OK 3_commit_push.sql (1.77ms)18672026/10/01 08:35:27 goose: up to current file version: 318682026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.22ms)18692026/10/01 08:35:27 OK 3_commit_push.sql (1.47ms)18702026/10/01 08:35:27 goose: up to current file version: 31871--- PASS: TestPushWaitsForSweepHoldingRow (1.24s)1872=== CONT TestClientErrorHandling1873=== RUN TestClientErrorHandling/InvalidStorePath1874=== PAUSE TestClientErrorHandling/InvalidStorePath1875=== RUN TestClientErrorHandling/InvalidAuthToken1876=== PAUSE TestClientErrorHandling/InvalidAuthToken1877=== RUN TestClientErrorHandling/ServerNotAvailable1878=== PAUSE TestClientErrorHandling/ServerNotAvailable1879=== CONT TestOrphanedObjectsGC18802026/10/01 08:35:27 OK 20241026095416_initial_model.sql (11.91ms)18812026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (11.44ms)1882--- PASS: TestReadProxyHead (0.56s)1883=== CONT TestClientCADerivations18842026/10/01 08:35:27 OK 20251218171726_add_pins.sql (8.32ms)18852026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)18862026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.6ms)18872026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.92ms)18882026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (3.09ms)18892026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000018902026-10-01 08:35:27.099 UTC [813] ERROR: relation "goose_db_version" does not exist at character 3618912026-10-01 08:35:27.099 UTC [813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18922026/10/01 08:35:27 OK 1_commit_pending_closure.sql (3.63ms)1893--- PASS: TestReadProxy404 (0.56s)1894=== CONT TestCacheStatsHandler18952026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.38ms)18962026/10/01 08:35:27 OK 3_commit_push.sql (1.91ms)18972026/10/01 08:35:27 goose: up to current file version: 318982026-10-01 08:35:27.112 UTC [815] ERROR: relation "goose_db_version" does not exist at character 3618992026-10-01 08:35:27.112 UTC [815] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19002026/10/01 08:35:27 OK 20241026095416_initial_model.sql (11.52ms)19012026-10-01 08:35:27.120 UTC [817] ERROR: relation "goose_db_version" does not exist at character 3619022026-10-01 08:35:27.120 UTC [817] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19032026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)19042026/10/01 08:35:27 OK 20251218171726_add_pins.sql (13.2ms)1905--- PASS: TestReadProxyNarStreaming (0.59s)1906=== CONT TestService_AuthMiddleware_OIDC19072026/10/01 08:35:27 OK 20241026095416_initial_model.sql (16.98ms)19082026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)19092026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)19102026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.51ms)19112026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.76ms)19122026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (3.14ms)19132026-10-01 08:35:27.148 UTC [818] ERROR: relation "goose_db_version" does not exist at character 3619142026-10-01 08:35:27.148 UTC [818] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19152026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.88ms)19162026-10-01 08:35:27.148 UTC [819] ERROR: relation "goose_db_version" does not exist at character 3619172026-10-01 08:35:27.148 UTC [819] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19182026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)19192026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (3.36ms)19202026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019212026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)19222026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.5ms)19232026/10/01 08:35:27 OK 1_commit_pending_closure.sql (3.3ms)19242026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.04ms)19252026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.17ms)19262026-10-01 08:35:27.156 UTC [820] ERROR: relation "goose_db_version" does not exist at character 3619272026-10-01 08:35:27.156 UTC [820] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19282026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.68ms)19292026/10/01 08:35:27 OK 3_commit_push.sql (1.4ms)19302026/10/01 08:35:27 goose: up to current file version: 319312026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.96ms)19322026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019332026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.7ms)19342026/10/01 08:35:27 OK 1_commit_pending_closure.sql (3.27ms)19352026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.54ms)19362026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.43ms)19372026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.71ms)19382026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.82ms)1939--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.59s)1940=== CONT TestService_NativeMTLS19412026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.72ms)19422026/10/01 08:35:27 OK 3_commit_push.sql (1.7ms)19432026/10/01 08:35:27 goose: up to current file version: 319442026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)19452026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)19462026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.25ms)19472026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019482026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.99ms)19492026/10/01 08:35:27 OK 20251218171726_add_pins.sql (4.04ms)19502026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.34ms)19512026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.87ms)19522026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)19532026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.67ms)19542026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)19552026-10-01 08:35:27.175 UTC [822] ERROR: relation "goose_db_version" does not exist at character 3619562026-10-01 08:35:27.175 UTC [822] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19572026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)19582026/10/01 08:35:27 OK 3_commit_push.sql (1.99ms)19592026/10/01 08:35:27 goose: up to current file version: 319602026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.65ms)19612026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.83ms)19622026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.44ms)19632026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.68ms)19642026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)19652026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.77ms)19662026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.99ms)19672026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019682026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.78ms)19692026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (3.21ms)19702026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019712026/10/01 08:35:27 OK 1_commit_pending_closure.sql (3.21ms)19722026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.78ms)19732026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.67ms)19742026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.65ms)19752026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.04ms)19762026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019772026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.72ms)19782026/10/01 08:35:27 OK 3_commit_push.sql (954.79µs)19792026/10/01 08:35:27 goose: up to current file version: 319802026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.62ms)19812026/10/01 08:35:27 OK 3_commit_push.sql (877.64µs)19822026/10/01 08:35:27 goose: up to current file version: 319832026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.45ms)19842026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)19852026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.92ms)19862026/10/01 08:35:27 OK 3_commit_push.sql (1.45ms)19872026/10/01 08:35:27 goose: up to current file version: 319882026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.34ms)1989--- PASS: TestReadProxyNarinfo (0.61s)19902026-10-01 08:35:27.198 UTC [824] ERROR: relation "goose_db_version" does not exist at character 3619912026-10-01 08:35:27.198 UTC [824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1992=== CONT TestService_ReadScope_PublicByDefault19932026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)19942026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.69ms)19952026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.21ms)19962026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.96ms)19972026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000019982026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.63ms)19992026/10/01 08:35:27 OK 20241026095416_initial_model.sql (7.93ms)20002026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.63ms)20012026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)20022026/10/01 08:35:27 OK 3_commit_push.sql (1.75ms)20032026/10/01 08:35:27 goose: up to current file version: 320042026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.83ms)20052026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)20062026/10/01 08:35:27 OK 20260905000000_add_claims.sql (4.16ms)20072026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.1ms)20082026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.15ms)20092026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000020102026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.58ms)20112026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.33ms)20122026/10/01 08:35:27 OK 3_commit_push.sql (1.35ms)20132026/10/01 08:35:27 goose: up to current file version: 320142026/10/01 08:35:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41127/oidc20152026-10-01 08:35:27.253 UTC [830] ERROR: relation "goose_db_version" does not exist at character 3620162026-10-01 08:35:27.253 UTC [830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20172026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.96ms)20182026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)20192026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.16ms)20202026/10/01 08:35:27 INFO Received uploads request method=POST path=/api/pending_closures20212026/10/01 08:35:27 INFO Received uploads request method=POST path=/api/pending_closures20222026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)20232026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.05ms)20242026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.39ms)20252026-10-01 08:35:27.292 UTC [848] ERROR: relation "goose_db_version" does not exist at character 3620262026-10-01 08:35:27.292 UTC [848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2027--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.60s)2028=== CONT TestService_RequireScope_OIDC20292026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.47ms)20302026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000020312026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.46ms)20322026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.4ms)20332026/10/01 08:35:27 OK 3_commit_push.sql (989.51µs)20342026/10/01 08:35:27 goose: up to current file version: 320352026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.63ms)20362026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)20372026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.28ms)20382026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)2039=== NAME TestClientWithDependencies2040 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2881257096/001/store/5xl4n3yyyfvv72pyfp1gbwcxaz7l6gy9-test-script20412026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.1ms)20422026/10/01 08:35:27 INFO Aborted multipart uploads count=020432026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (1.37ms)20442026/10/01 08:35:27 WARN Force mode enabled - objects will be deleted immediately without grace period20452026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (984.36µs)20462026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000020472026/10/01 08:35:27 OK 1_commit_pending_closure.sql (1.41ms)20482026/10/01 08:35:27 OK 2_object_stats_trigger.sql (667.65µs)20492026/10/01 08:35:27 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=020502026/10/01 08:35:27 OK 3_commit_push.sql (719.97µs)20512026/10/01 08:35:27 goose: up to current file version: 320522026/10/01 08:35:27 INFO Vacuumed table table=pending_closures20532026/10/01 08:35:27 INFO Vacuumed table table=pending_objects20542026/10/01 08:35:27 INFO Vacuumed table table=multipart_uploads20552026/10/01 08:35:27 INFO Vacuumed table table=closures20562026/10/01 08:35:27 INFO Vacuumed table table=objects20572026-10-01 08:35:27.323 UTC [868] ERROR: relation "goose_db_version" does not exist at character 3620582026-10-01 08:35:27.323 UTC [868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2059--- PASS: TestGCMetrics (0.62s)2060=== CONT TestMultipartCleanup20612026/10/01 08:35:27 OK 20241026095416_initial_model.sql (7.14ms)20622026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)20632026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.74ms)20642026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)20652026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.71ms)2066=== NAME TestClientWithDependencies2067 client_integration_test.go:615: Found 1 dependencies (including self)20682026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.2ms)20692026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.51ms)20702026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000020712026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.37ms)20722026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.39ms)20732026/10/01 08:35:27 OK 3_commit_push.sql (1.55ms)20742026/10/01 08:35:27 goose: up to current file version: 320752026/10/01 08:35:27 INFO Aborted multipart uploads count=020762026/10/01 08:35:27 INFO lead: acquired remote=192.0.2.1:123420772026/10/01 08:35:27 INFO lead: released remote=192.0.2.1:12342078--- PASS: TestLeadEndsOnShutdown (0.54s)2079=== CONT TestServerTLSConfig2080=== RUN TestServerTLSConfig/no_client_CA2081=== PAUSE TestServerTLSConfig/no_client_CA2082=== RUN TestServerTLSConfig/missing_CA_file2083=== PAUSE TestServerTLSConfig/missing_CA_file2084=== RUN TestServerTLSConfig/not_a_PEM_file2085=== PAUSE TestServerTLSConfig/not_a_PEM_file2086=== CONT TestService_AuthMiddleware_MTLSProxyHeader20872026/10/01 08:35:27 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=020882026/10/01 08:35:27 INFO Vacuumed table table=pending_closures20892026/10/01 08:35:27 INFO Vacuumed table table=pending_objects20902026/10/01 08:35:27 INFO Vacuumed table table=multipart_uploads20912026/10/01 08:35:27 INFO Vacuumed table table=closures20922026/10/01 08:35:27 INFO Vacuumed table table=objects20932026/10/01 08:35:27 INFO Aborted multipart uploads count=020942026/10/01 08:35:27 WARN Force mode enabled - objects will be deleted immediately without grace period20952026/10/01 08:35:27 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=020962026/10/01 08:35:27 INFO Vacuumed table table=pending_closures20972026/10/01 08:35:27 INFO Vacuumed table table=pending_objects20982026/10/01 08:35:27 INFO Vacuumed table table=multipart_uploads20992026/10/01 08:35:27 INFO Vacuumed table table=closures21002026/10/01 08:35:27 INFO Vacuumed table table=objects2101--- PASS: TestPushDedupSurvivesConcurrentGC (0.68s)2102=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21032026/10/01 08:35:27 INFO lead: acquired remote=192.0.2.1:123421042026-10-01 08:35:27.407 UTC [912] ERROR: relation "goose_db_version" does not exist at character 3621052026-10-01 08:35:27.407 UTC [912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21062026/10/01 08:35:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37725/oidc21072026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.71ms)21082026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes21092026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (9.28ms)21102026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.82ms)21112026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)21122026/10/01 08:35:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21132026/10/01 08:35:27 INFO Uploading 5xl4n3yyyfvv72pyfp1gbwcxaz7l6gy9-test-script (136B)21142026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.43ms)21152026/10/01 08:35:27 WARN Failed to register uploaded object key=log/crndfjdnlw2k0ycjzsmz3bzv55pyc4rr-test-script.drv error="server returned 404: 404 page not found\n"21162026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.43ms)21172026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21182026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21192026/10/01 08:35:27 WARN Failed to register uploaded object key=5xl4n3yyyfvv72pyfp1gbwcxaz7l6gy9.ls error="server returned 404: 404 page not found\n"21202026/10/01 08:35:27 INFO Signed narinfos id=1 count=121212026/10/01 08:35:27 INFO Uploading 1 narinfos21222026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.83ms)21232026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000021242026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.78ms)21252026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete21262026/10/01 08:35:27 WARN Failed to register uploaded object key=5xl4n3yyyfvv72pyfp1gbwcxaz7l6gy9.narinfo error="server returned 404: 404 page not found\n"21272026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.12ms)21282026/10/01 08:35:27 OK 3_commit_push.sql (1.72ms)21292026/10/01 08:35:27 goose: up to current file version: 321302026-10-01 08:35:27.463 UTC [950] ERROR: relation "goose_db_version" does not exist at character 3621312026-10-01 08:35:27.463 UTC [950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21322026/10/01 08:35:27 INFO Upload complete. (77ms)2133=== NAME TestClientWithDependencies2134 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2881257096/001/store) requires matching store prefix2135--- PASS: TestClientWithDependencies (0.79s)2136=== CONT TestMetricsInventory21372026/10/01 08:35:27 OK 20241026095416_initial_model.sql (7.91ms)21382026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)21392026-10-01 08:35:27.478 UTC [953] ERROR: relation "goose_db_version" does not exist at character 3621402026-10-01 08:35:27.478 UTC [953] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21412026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.8ms)21422026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)21432026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.61ms)21442026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.33ms)21452026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.13ms)21462026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000021472026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.77ms)21482026/10/01 08:35:27 OK 1_commit_pending_closure.sql (1.89ms)21492026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)21502026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.98ms)21512026/10/01 08:35:27 OK 3_commit_push.sql (1.2ms)21522026/10/01 08:35:27 goose: up to current file version: 321532026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.96ms)21542026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)21552026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.63ms)21562026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.4ms)21572026-10-01 08:35:27.510 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 3621582026-10-01 08:35:27.510 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21592026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.91ms)21602026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000021612026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.16ms)21622026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1ms)21632026/10/01 08:35:27 OK 3_commit_push.sql (685.04µs)21642026/10/01 08:35:27 goose: up to current file version: 321652026/10/01 08:35:27 INFO Starting HTTP server address=127.0.0.1:4228521662026/10/01 08:35:27 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1014223757/001/proxy.sock21672026/10/01 08:35:27 WARN mTLS auth: subject not in bound subjects subject="CN=someone"21682026/10/01 08:35:27 INFO Shutdown signal received, draining in-flight requests timeout=10s2169--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.58s)2170=== CONT TestService_ReadAuthMiddleware21712026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.52ms)21722026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)21732026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.76ms)21742026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)21752026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.82ms)21762026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.54ms)21772026/10/01 08:35:27 INFO lead: released remote=192.0.2.1:123421782026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.93ms)21792026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000021802026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.36ms)21812026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.52ms)21822026/10/01 08:35:27 OK 3_commit_push.sql (785.28µs)21832026/10/01 08:35:27 goose: up to current file version: 321842026-10-01 08:35:27.554 UTC [1078] ERROR: relation "goose_db_version" does not exist at character 3621852026-10-01 08:35:27.554 UTC [1078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2186--- PASS: TestGCBugBareHashReferences (0.81s)2187=== CONT TestNARDeduplicationMetadataUploadBug21882026/10/01 08:35:27 OK 20241026095416_initial_model.sql (7.91ms)21892026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)21902026/10/01 08:35:27 OK 20251218171726_add_pins.sql (11.01ms)21912026/10/01 08:35:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21922026/10/01 08:35:27 WARN Refused reserved pin name=worker-x86_64-linux21932026/10/01 08:35:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux21942026/10/01 08:35:27 INFO Received create pin request method=POST path=/api/pins/my-app21952026/10/01 08:35:27 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2196--- PASS: TestCreatePin_ReservedPins (0.66s)2197=== CONT TestProxyWriteTimeout/narinfo2198=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21992026/10/01 08:35:27 INFO Received uploads request method=POST path=/2200=== CONT TestProxyWriteTimeout/10_GiB_nar2201=== CONT TestProxyWriteTimeout/unknown_size2202=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22032026/10/01 08:35:27 INFO Received complete multipart upload request method=POST path=/2204=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22052026/10/01 08:35:27 INFO Received request for more parts method=POST path=/2206=== CONT TestProxyWriteTimeout/1_GiB_nar2207--- PASS: TestProxyWriteTimeout (0.09s)2208 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2209 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2210 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2211 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2212=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22132026/10/01 08:35:27 INFO Received uploads request method=POST path=/2214--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)2215 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2216 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2217 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2218 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2219=== CONT TestIsValidUploadKey/narinfo2220=== CONT TestIsValidUploadKey/realisation_plus_in_output2221=== CONT TestIsValidUploadKey/unknown_type2222=== CONT TestIsValidUploadKey/empty_key2223=== CONT TestIsValidUploadKey/absolute2224=== CONT TestIsValidUploadKey/traversal_nar2225=== CONT TestIsValidUploadKey/traversal2226=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2227=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2228=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2229=== CONT TestIsValidUploadKey/index.html2230=== CONT TestIsValidUploadKey/nix-cache-info2231=== CONT TestIsValidUploadKey/build_log_equals2232=== CONT TestIsValidUploadKey/realisation2233=== CONT TestIsValidUploadKey/nar_plain2234=== CONT TestIsValidUploadKey/build_log2235=== CONT TestIsValidUploadKey/listing2236=== CONT TestIsValidUploadKey/build_log_question_mark2237=== CONT TestIsValidUploadKey/nar_xz2238=== CONT TestIsValidUploadKey/nar_zst2239=== CONT TestIsValidUploadKey/build_log_plus_in_name2240=== CONT TestIsValidUploadKey/build_log_home-manager_file2241--- PASS: TestIsValidUploadKey (0.10s)2242 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2243 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2244 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2245 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2246 --- PASS: TestIsValidUploadKey/absolute (0.00s)2247 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2248 --- PASS: TestIsValidUploadKey/traversal (0.00s)2249 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2250 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2251 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2252 --- PASS: TestIsValidUploadKey/index.html (0.00s)2253 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2254 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2255 --- PASS: TestIsValidUploadKey/realisation (0.00s)2256 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2257 --- PASS: TestIsValidUploadKey/build_log (0.00s)2258 --- PASS: TestIsValidUploadKey/listing (0.00s)2259 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2260 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2261 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2262 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2263 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2264=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22652026/10/01 08:35:27 INFO Received uploads request method=POST path=/22662026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)2267--- PASS: TestObjectStatsTrigger (0.61s)2268=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22692026/10/01 08:35:27 INFO Received complete multipart upload request method=POST path=/2270=== NAME TestPinProtectsFromGC2271 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2154766782/001/store/9lpayck1namcmh6hxkl1xavhv237rxhg-pinned-file.txt22722026/10/01 08:35:27 INFO lead: acquired remote=192.0.2.1:12342273 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2154766782/001/store/6vyw5ra6snj7xwad0061wr9acvqrfj1f-unpinned-file.txt22742026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.91ms)22752026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.37ms)22762026/10/01 08:35:27 INFO lead: released remote=192.0.2.1:123422772026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.38ms)2278--- PASS: TestLeadElectsOneAndHandsOver (0.76s)22792026/10/01 08:35:27 goose: successfully migrated database to version: 202609231200002280=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22812026/10/01 08:35:27 INFO Received request for more parts method=POST path=/22822026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.52ms)22832026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes22842026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.14ms)22852026/10/01 08:35:27 OK 3_commit_push.sql (1.43ms)22862026/10/01 08:35:27 goose: up to current file version: 322872026/10/01 08:35:27 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)22882026/10/01 08:35:27 INFO Uploading v183yaxvs0dlnszvl30bjs28k4jlf78k-top (224B)22892026/10/01 08:35:27 INFO Uploading n7kndgs69vnjr9sax19l0gsj587qgzq2-shared-dep (136B)22902026/10/01 08:35:27 INFO Received uploads request method=POST path=/api/pending_closures22912026-10-01 08:35:27.605 UTC [1189] ERROR: relation "goose_db_version" does not exist at character 3622922026-10-01 08:35:27.605 UTC [1189] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22932026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22942026/10/01 08:35:27 WARN Failed to register uploaded object key=n7kndgs69vnjr9sax19l0gsj587qgzq2.ls error="server returned 404: 404 page not found\n"22952026/10/01 08:35:27 WARN Failed to register uploaded object key=v183yaxvs0dlnszvl30bjs28k4jlf78k.ls error="server returned 404: 404 page not found\n"22962026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22972026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1lxvrb6ml0h22606cdibn3f1bgkw9773410dvlbmzlbqlm1n5k59.nar.zst error="server returned 404: 404 page not found\n"22982026/10/01 08:35:27 INFO Signed narinfos id=1 count=222992026/10/01 08:35:27 INFO Uploading 2 narinfos23002026/10/01 08:35:27 INFO Received uploads request method=POST path=/api/pending_closures23012026/10/01 08:35:27 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)23022026/10/01 08:35:27 INFO Uploading jqx6072nlh4xin4rbvcg8750j8k7c0da-a (216B)23032026/10/01 08:35:27 INFO Uploading zy3n1xr67lzh021izrvnk8arhqn0s5b8-shared-dep (136B)23042026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.35ms)23052026/10/01 08:35:27 WARN Failed to register uploaded object key=n7kndgs69vnjr9sax19l0gsj587qgzq2.narinfo error="server returned 404: 404 page not found\n"23062026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete23072026/10/01 08:35:27 WARN Failed to register uploaded object key=v183yaxvs0dlnszvl30bjs28k4jlf78k.narinfo error="server returned 404: 404 page not found\n"23082026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)23092026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23102026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/0kys3zgxl5gvp731xy2j5swh9mappa6b4nj54wy4lsj9lpmg47ys.nar.zst error="server returned 404: 404 page not found\n"23112026/10/01 08:35:27 WARN Failed to register uploaded object key=jqx6072nlh4xin4rbvcg8750j8k7c0da.ls error="server returned 404: 404 page not found\n"23122026/10/01 08:35:27 WARN Failed to register uploaded object key=zy3n1xr67lzh021izrvnk8arhqn0s5b8.ls error="server returned 404: 404 page not found\n"23132026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23142026/10/01 08:35:27 WARN Failed to register uploaded object key=3h3albiv93khy6gxa4i17iqsrbrgjhj0.ls error="server returned 404: 404 page not found\n"23152026/10/01 08:35:27 INFO Signed narinfos id=1 count=223162026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23172026/10/01 08:35:27 INFO Signed narinfos id=2 count=223182026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.56ms)23192026/10/01 08:35:27 INFO Uploading 4 narinfos23202026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)23212026/10/01 08:35:27 WARN Failed to register uploaded object key=3h3albiv93khy6gxa4i17iqsrbrgjhj0.narinfo error="server returned 404: 404 page not found\n"23222026/10/01 08:35:27 WARN Failed to register uploaded object key=jqx6072nlh4xin4rbvcg8750j8k7c0da.narinfo error="server returned 404: 404 page not found\n"23232026/10/01 08:35:27 WARN Failed to register uploaded object key=zy3n1xr67lzh021izrvnk8arhqn0s5b8.narinfo error="server returned 404: 404 page not found\n"23242026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.53ms)23252026/10/01 08:35:27 INFO Upload complete. (72ms)2326=== NAME TestClientSharedPathCommittedMidPush23272026/10/01 08:35:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2328 client_integration_test.go:680: Retrieved narinfo from S3:23292026/10/01 08:35:27 WARN Failed to register uploaded object key=zy3n1xr67lzh021izrvnk8arhqn0s5b8.narinfo error="server returned 404: 404 page not found\n"2330 StorePath: /build/TestClientSharedPathCommittedMidPush4269947419/001/store/n7kndgs69vnjr9sax19l0gsj587qgzq2-shared-dep2331 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2332 Compression: zstd2333 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822334 NarSize: 1362335 References: 2336 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n23372026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.08ms)2338 client_integration_test.go:680: Retrieved narinfo from S3:2339 StorePath: /build/TestClientSharedPathCommittedMidPush4269947419/001/store/v183yaxvs0dlnszvl30bjs28k4jlf78k-top2340 URL: nar/1lxvrb6ml0h22606cdibn3f1bgkw9773410dvlbmzlbqlm1n5k59.nar.zst2341 Compression: zstd2342 NarHash: sha256:1lxvrb6ml0h22606cdibn3f1bgkw9773410dvlbmzlbqlm1n5k592343 NarSize: 2242344 References: /build/TestClientSharedPathCommittedMidPush4269947419/001/store/n7kndgs69vnjr9sax19l0gsj587qgzq2-shared-dep2345 CA: text:sha256:1pfq5l1aq6kph6xdbs2f5413w421viy4wyzsi8z5vswvcz6bg25l23462026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (2.38ms)23472026/10/01 08:35:27 goose: successfully migrated database to version: 202609231200002348=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows23492026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.16ms)23502026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1ms)23512026/10/01 08:35:27 OK 3_commit_push.sql (859.18µs)23522026/10/01 08:35:27 goose: up to current file version: 32353--- PASS: TestClientSharedPathCommittedMidPush (0.75s)2354=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check23552026/10/01 08:35:27 INFO Completed upload id=123562026/10/01 08:35:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23572026/10/01 08:35:27 INFO Completed upload id=223582026/10/01 08:35:27 INFO Upload complete. (83ms)2359=== NAME TestClientFallsBackToClosures2360 client_pushes_test.go:112: Retrieved narinfo from S3:2361 StorePath: /build/TestClientFallsBackToClosures1257328054/001/store/zy3n1xr67lzh021izrvnk8arhqn0s5b8-shared-dep2362 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2363 Compression: zstd2364 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822365 NarSize: 1362366 References: 2367 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2368 client_pushes_test.go:112: Retrieved narinfo from S3:2369 StorePath: /build/TestClientFallsBackToClosures1257328054/001/store/jqx6072nlh4xin4rbvcg8750j8k7c0da-a2370 URL: nar/0kys3zgxl5gvp731xy2j5swh9mappa6b4nj54wy4lsj9lpmg47ys.nar.zst2371 Compression: zstd2372 NarHash: sha256:0kys3zgxl5gvp731xy2j5swh9mappa6b4nj54wy4lsj9lpmg47ys2373 NarSize: 2162374 References: /build/TestClientFallsBackToClosures1257328054/001/store/zy3n1xr67lzh021izrvnk8arhqn0s5b8-shared-dep2375 CA: text:sha256:15kw20n6x9ggbfib2ys5czf044drx1rhvyp0cx7rqb0mc610hx102376=== CONT TestIsValidCachePath/narinfo2377=== CONT TestIsValidCachePath/index.html2378=== CONT TestIsValidCachePath/nix-cache-info2379=== CONT TestIsValidCachePath/realisation2380=== CONT TestIsValidCachePath/log2381=== CONT TestIsValidCachePath/ls2382=== CONT TestIsValidCachePath/nar_uncompressed2383=== CONT TestIsValidCachePath/nar_bz22384=== CONT TestIsValidCachePath/nar_xz2385=== CONT TestIsValidCachePath/nar_zst2386=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2387=== NAME TestClientFallsBackToClosures2388 client_pushes_test.go:112: Retrieved narinfo from S3:2389 StorePath: /build/TestClientFallsBackToClosures1257328054/001/store/3h3albiv93khy6gxa4i17iqsrbrgjhj0-b2390 URL: nar/0kys3zgxl5gvp731xy2j5swh9mappa6b4nj54wy4lsj9lpmg47ys.nar.zst2391 Compression: zstd2392 NarHash: sha256:0kys3zgxl5gvp731xy2j5swh9mappa6b4nj54wy4lsj9lpmg47ys2393 NarSize: 2162394 References: /build/TestClientFallsBackToClosures1257328054/001/store/zy3n1xr67lzh021izrvnk8arhqn0s5b8-shared-dep2395 CA: text:sha256:15kw20n6x9ggbfib2ys5czf044drx1rhvyp0cx7rqb0mc610hx102396=== CONT TestIsValidCachePath/empty2397=== CONT TestIsValidCachePath/traversal_parent2398=== NAME TestClientMultipleUploads2399 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3025668029/001/store/3l7dzji4i0lin53ljvq8ccdaxm5faidi-test-file-0.txt2400=== CONT TestIsValidCachePath/random_path2401=== CONT TestIsValidCachePath/invalid_char_u2402=== CONT TestIsValidCachePath/invalid_char_e2403=== CONT TestIsValidCachePath/traversal_in_middle2404=== CONT TestIsValidCachePath/wrong_extension2405=== CONT TestIsValidCachePath/short_hash2406=== CONT TestIsValidCachePath/leading_slash2407--- PASS: TestIsValidCachePath (0.00s)2408 --- PASS: TestIsValidCachePath/narinfo (0.00s)2409 --- PASS: TestIsValidCachePath/index.html (0.00s)2410 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2411 --- PASS: TestIsValidCachePath/realisation (0.00s)2412 --- PASS: TestIsValidCachePath/log (0.00s)2413 --- PASS: TestIsValidCachePath/ls (0.00s)2414 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2415 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2416 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2417 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2418 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2419 --- PASS: TestIsValidCachePath/empty (0.00s)2420 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2421 --- PASS: TestIsValidCachePath/random_path (0.00s)2422 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2423 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2424 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2425 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2426 --- PASS: TestIsValidCachePath/short_hash (0.00s)2427 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2428=== CONT TestPush_RejectsBadRequests/no_roots24292026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes2430=== CONT TestPush_RejectsBadRequests/bad_root24312026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes2432=== CONT TestPush_RejectsBadRequests/root_not_in_objects24332026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes2434=== CONT TestPush_RejectsBadRequests/no_objects24352026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes2436=== CONT TestResolveDBConnectionString/flag_wins2437--- PASS: TestPush_RejectsBadRequests (0.72s)2438 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2439 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2440 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2441 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2442=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2443=== CONT TestResolveDBConnectionString/nothing_configured2444=== CONT TestResolveDBConnectionString/missing_file_is_an_error2445=== CONT TestResolveDBConnectionString/file_when_flag_empty2446=== CONT TestParseSingleRange/none2447=== CONT TestParseSingleRange/start_past_EOF2448=== CONT TestParseSingleRange/single_byte2449=== CONT TestParseSingleRange/suffix_exceeds_size2450--- PASS: TestResolveDBConnectionString (0.00s)2451 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2452 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2453 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2454 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2455 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2456=== CONT TestParseSingleRange/suffix2457=== CONT TestParseSingleRange/end_clamped_to_size2458=== CONT TestParseSingleRange/start_far_past_EOF2459=== CONT TestParseSingleRange/open-ended2460=== CONT TestParseSingleRange/closed2461=== CONT TestParseSingleRange/malformed_end_before_start2462=== CONT TestParseSingleRange/malformed_both_empty2463=== CONT TestParseSingleRange/malformed_no_dash2464=== CONT TestParseSingleRange/multi-range_ignored2465=== CONT TestParseSingleRange/unknown_unit2466--- PASS: TestParseSingleRange (0.00s)2467 --- PASS: TestParseSingleRange/none (0.00s)2468 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2469 --- PASS: TestParseSingleRange/single_byte (0.00s)2470 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2471 --- PASS: TestParseSingleRange/suffix (0.00s)2472 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2473 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2474 --- PASS: TestParseSingleRange/open-ended (0.00s)2475 --- PASS: TestParseSingleRange/closed (0.00s)2476 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2477 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2478 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2479 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2480 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2481=== CONT TestCacheConfigHandler/full_config,_no_issuer2482=== CONT TestCacheConfigHandler/no_signing_keys2483=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2484=== CONT TestCacheConfigHandler/no_cache_url_configured2485--- PASS: TestCacheConfigHandler (0.00s)2486 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2487 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2488 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2489 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2490=== CONT TestClientErrorHandling/InvalidStorePath2491--- PASS: TestClientFallsBackToClosures (0.78s)2492=== CONT TestClientErrorHandling/ServerNotAvailable24932026-10-01 08:35:27.654 UTC [1247] ERROR: relation "goose_db_version" does not exist at character 3624942026-10-01 08:35:27.654 UTC [1247] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24952026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes24962026/10/01 08:35:27 OK 20241026095416_initial_model.sql (8.83ms)24972026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes24982026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)24992026/10/01 08:35:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25002026/10/01 08:35:27 INFO Uploading 9lpayck1namcmh6hxkl1xavhv237rxhg-pinned-file.txt (128B)25012026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.42ms)25022026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"25032026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25042026/10/01 08:35:27 WARN Failed to register uploaded object key=9lpayck1namcmh6hxkl1xavhv237rxhg.ls error="server returned 404: 404 page not found\n"25052026/10/01 08:35:27 INFO Signed narinfos id=1 count=125062026/10/01 08:35:27 INFO Uploading 1 narinfos25072026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.42ms)25082026/10/01 08:35:27 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)25092026/10/01 08:35:27 INFO Uploading miclg0iga90zldnsc1pbcps5954xwmcl-shared-dep (136B)25102026/10/01 08:35:27 INFO Uploading jn4svbynq89dyjw9brkgb510ry197gk7-b (216B)25112026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete25122026/10/01 08:35:27 WARN Failed to register uploaded object key=9lpayck1namcmh6hxkl1xavhv237rxhg.narinfo error="server returned 404: 404 page not found\n"25132026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.72ms)25142026/10/01 08:35:27 WARN Failed to register uploaded object key=5ar96pmx363vhj3h5bckn0h0h960nh2h.ls error="server returned 404: 404 page not found\n"25152026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"25162026/10/01 08:35:27 WARN Failed to register uploaded object key=miclg0iga90zldnsc1pbcps5954xwmcl.ls error="server returned 404: 404 page not found\n"25172026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1h6362mbl0r7hv0bd0x3k91h1qklr70fkzp5q359j2f2qlqanlf9.nar.zst error="server returned 404: 404 page not found\n"25182026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (3.48ms)25192026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25202026/10/01 08:35:27 WARN Failed to register uploaded object key=jn4svbynq89dyjw9brkgb510ry197gk7.ls error="server returned 404: 404 page not found\n"2521=== NAME TestClientMultipleUploads25222026/10/01 08:35:27 INFO Signed narinfos id=1 count=32523 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3025668029/001/store/s98hz2spkwy2ix0cdzdwjaxy7lm420kc-test-file-1.txt25242026/10/01 08:35:27 INFO Upload complete. (65ms)25252026/10/01 08:35:27 INFO Uploading 3 narinfos25262026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.96ms)25272026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000025282026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.27ms)25292026/10/01 08:35:27 WARN Failed to register uploaded object key=jn4svbynq89dyjw9brkgb510ry197gk7.narinfo error="server returned 404: 404 page not found\n"25302026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.41ms)25312026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete25322026/10/01 08:35:27 WARN Failed to register uploaded object key=miclg0iga90zldnsc1pbcps5954xwmcl.narinfo error="server returned 404: 404 page not found\n"25332026/10/01 08:35:27 WARN Failed to register uploaded object key=5ar96pmx363vhj3h5bckn0h0h960nh2h.narinfo error="server returned 404: 404 page not found\n"25342026/10/01 08:35:27 OK 3_commit_push.sql (1.35ms)25352026/10/01 08:35:27 goose: up to current file version: 32536=== NAME TestClientIntegration2537 client_integration_test.go:286: Created store path: /build/TestClientIntegration3913055656/002/store/5kimq7zq1229n6fz2j1a36i2k7vxshif-test-file.txt25382026/10/01 08:35:27 INFO Upload complete. (77ms)2539=== NAME TestClientPushesUseOnePush2540 client_pushes_test.go:97: Retrieved narinfo from S3:2541 StorePath: /build/TestClientPushesUseOnePush4146811754/001/store/miclg0iga90zldnsc1pbcps5954xwmcl-shared-dep2542 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2543 Compression: zstd2544 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822545 NarSize: 1362546 References: 2547 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2548 client_pushes_test.go:97: Retrieved narinfo from S3:2549 StorePath: /build/TestClientPushesUseOnePush4146811754/001/store/5ar96pmx363vhj3h5bckn0h0h960nh2h-a2550 URL: nar/1h6362mbl0r7hv0bd0x3k91h1qklr70fkzp5q359j2f2qlqanlf9.nar.zst2551 Compression: zstd2552 NarHash: sha256:1h6362mbl0r7hv0bd0x3k91h1qklr70fkzp5q359j2f2qlqanlf92553 NarSize: 2162554 References: /build/TestClientPushesUseOnePush4146811754/001/store/miclg0iga90zldnsc1pbcps5954xwmcl-shared-dep2555 CA: text:sha256:1n57ahxhkgwzl43d0ixnh0jf8rrmk1ysb0f0446czmdbwp0dr21z2556 client_pushes_test.go:97: Retrieved narinfo from S3:2557 StorePath: /build/TestClientPushesUseOnePush4146811754/001/store/jn4svbynq89dyjw9brkgb510ry197gk7-b2558 URL: nar/1h6362mbl0r7hv0bd0x3k91h1qklr70fkzp5q359j2f2qlqanlf9.nar.zst2559 Compression: zstd2560 NarHash: sha256:1h6362mbl0r7hv0bd0x3k91h1qklr70fkzp5q359j2f2qlqanlf92561 NarSize: 2162562 References: /build/TestClientPushesUseOnePush4146811754/001/store/miclg0iga90zldnsc1pbcps5954xwmcl-shared-dep2563 CA: text:sha256:1n57ahxhkgwzl43d0ixnh0jf8rrmk1ysb0f0446czmdbwp0dr21z2564--- PASS: TestClientPushesUseOnePush (0.84s)2565=== CONT TestClientErrorHandling/InvalidAuthToken2566=== NAME TestClientMultipleUploads2567 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3025668029/001/store/s4z58a0mn08z48z014sj7c0xss5xkzlj-test-file-2.txt25682026/10/01 08:35:27 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/present25692026/10/01 08:35:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"25702026/10/01 08:35:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2571--- PASS: TestService_NativeMTLS (0.58s)2572=== CONT TestServerTLSConfig/no_client_CA2573=== CONT TestServerTLSConfig/not_a_PEM_file2574=== CONT TestServerTLSConfig/missing_CA_file2575--- PASS: TestServerTLSConfig (0.00s)2576 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2577 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2578 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)25792026-10-01 08:35:27.755 UTC [1432] ERROR: relation "goose_db_version" does not exist at character 3625802026-10-01 08:35:27.755 UTC [1432] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25812026-10-01 08:35:27.755 UTC [1431] ERROR: relation "goose_db_version" does not exist at character 3625822026-10-01 08:35:27.755 UTC [1431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25832026-10-01 08:35:27.755 UTC [1433] ERROR: relation "goose_db_version" does not exist at character 3625842026-10-01 08:35:27.755 UTC [1433] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2585--- PASS: TestCacheStatsHandler (0.65s)25862026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes25872026/10/01 08:35:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25882026/10/01 08:35:27 INFO Uploading 6vyw5ra6snj7xwad0061wr9acvqrfj1f-unpinned-file.txt (128B)25892026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes25902026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"25912026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign25922026/10/01 08:35:27 WARN Failed to register uploaded object key=6vyw5ra6snj7xwad0061wr9acvqrfj1f.ls error="server returned 404: 404 page not found\n"25932026/10/01 08:35:27 INFO Signed narinfos id=2 count=125942026/10/01 08:35:27 INFO Uploading 1 narinfos25952026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/2/complete25962026/10/01 08:35:27 WARN Failed to register uploaded object key=6vyw5ra6snj7xwad0061wr9acvqrfj1f.narinfo error="server returned 404: 404 page not found\n"25972026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.11ms)25982026/10/01 08:35:27 OK 20241026095416_initial_model.sql (9.08ms)25992026/10/01 08:35:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2600--- PASS: TestService_ReadScope_PublicByDefault (0.57s)26012026/10/01 08:35:27 INFO Uploading 5kimq7zq1229n6fz2j1a36i2k7vxshif-test-file.txt (152B)26022026/10/01 08:35:27 OK 20241026095416_initial_model.sql (10.12ms)26032026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)26042026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)26052026/10/01 08:35:27 INFO Upload complete. (51ms)26062026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)26072026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.53ms)26082026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"26092026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26102026/10/01 08:35:27 WARN Failed to register uploaded object key=5kimq7zq1229n6fz2j1a36i2k7vxshif.ls error="server returned 404: 404 page not found\n"26112026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.52ms)26122026/10/01 08:35:27 INFO Signed narinfos id=1 count=126132026/10/01 08:35:27 INFO Uploading 1 narinfos26142026/10/01 08:35:27 OK 20251218171726_add_pins.sql (3.42ms)26152026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)26162026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)26172026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete26182026/10/01 08:35:27 WARN Failed to register uploaded object key=5kimq7zq1229n6fz2j1a36i2k7vxshif.narinfo error="server returned 404: 404 page not found\n"26192026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.8ms)26202026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)26212026/10/01 08:35:27 OK 20260905000000_add_claims.sql (3.18ms)26222026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.26ms)26232026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.52ms)26242026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000026252026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.89ms)26262026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (2.16ms)26272026/10/01 08:35:27 INFO Upload complete. (56ms)26282026/10/01 08:35:27 OK 1_commit_pending_closure.sql (1.96ms)26292026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.83ms)26302026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000026312026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (1.95ms)26322026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.33ms)26332026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.88ms)26342026/10/01 08:35:27 goose: successfully migrated database to version: 2026092312000026352026/10/01 08:35:27 OK 3_commit_push.sql (1.56ms)26362026/10/01 08:35:27 goose: up to current file version: 326372026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.91ms)26382026/10/01 08:35:27 OK 1_commit_pending_closure.sql (2.55ms)26392026/10/01 08:35:27 OK 2_object_stats_trigger.sql (2.52ms)26402026/10/01 08:35:27 OK 2_object_stats_trigger.sql (1.31ms)26412026/10/01 08:35:27 OK 3_commit_push.sql (1.34ms)26422026/10/01 08:35:27 goose: up to current file version: 326432026/10/01 08:35:27 OK 3_commit_push.sql (1.46ms)26442026/10/01 08:35:27 goose: up to current file version: 32645=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2646=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2647=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2648=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2649=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2650=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2651=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2652=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2653=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2654=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2655=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected26562026/10/01 08:35:27 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]2657=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured26582026/10/01 08:35:27 WARN Authentication failed token_preview=eyJhbGciOi...x486i2swBA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2659=== NAME TestClientCADerivations2660 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2181080612/001/store/sqcspvhvvjhl7kdp5gzddrng6nsln1k2-ca-test2661--- PASS: TestService_AuthMiddleware_OIDC (0.66s)2662 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2663 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2664 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2665 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)26662026/10/01 08:35:27 INFO Received create pin request method=POST path=/api/pins/myapp26672026-10-01 08:35:27.811 UTC [1523] ERROR: relation "goose_db_version" does not exist at character 3626682026-10-01 08:35:27.811 UTC [1523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26692026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes26702026/10/01 08:35:27 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2154766782/001/store/9lpayck1namcmh6hxkl1xavhv237rxhg-pinned-file.txt narinfo_key=9lpayck1namcmh6hxkl1xavhv237rxhg.narinfo26712026/10/01 08:35:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures26722026/10/01 08:35:27 INFO Garbage collection started26732026/10/01 08:35:27 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)26742026/10/01 08:35:27 INFO Uploading 3l7dzji4i0lin53ljvq8ccdaxm5faidi-test-file-0.txt (160B)26752026/10/01 08:35:27 INFO Uploading s4z58a0mn08z48z014sj7c0xss5xkzlj-test-file-2.txt (160B)26762026/10/01 08:35:27 INFO Uploading s98hz2spkwy2ix0cdzdwjaxy7lm420kc-test-file-1.txt (160B)26772026/10/01 08:35:27 INFO Received uploads request method=POST path=/api/pending_closures26782026/10/01 08:35:27 OK 20241026095416_initial_model.sql (7.74ms)26792026/10/01 08:35:27 INFO Aborted multipart uploads count=026802026/10/01 08:35:27 WARN Failed to register uploaded object key=s98hz2spkwy2ix0cdzdwjaxy7lm420kc.ls error="server returned 404: 404 page not found\n"26812026/10/01 08:35:27 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)26822026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"26832026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"26842026/10/01 08:35:27 WARN Failed to register uploaded object key=3l7dzji4i0lin53ljvq8ccdaxm5faidi.ls error="server returned 404: 404 page not found\n"26852026/10/01 08:35:27 WARN Failed to register uploaded object key=s4z58a0mn08z48z014sj7c0xss5xkzlj.ls error="server returned 404: 404 page not found\n"26862026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26872026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"26882026/10/01 08:35:27 WARN Force mode enabled - objects will be deleted immediately without grace period26892026/10/01 08:35:27 INFO Signed narinfos id=1 count=326902026/10/01 08:35:27 INFO Uploading 3 narinfos26912026/10/01 08:35:27 OK 20251218171726_add_pins.sql (2.3ms)26922026/10/01 08:35:27 WARN Failed to register uploaded object key=3l7dzji4i0lin53ljvq8ccdaxm5faidi.narinfo error="server returned 404: 404 page not found\n"26932026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete26942026/10/01 08:35:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.409235ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26952026/10/01 08:35:27 WARN Failed to register uploaded object key=s4z58a0mn08z48z014sj7c0xss5xkzlj.narinfo error="server returned 404: 404 page not found\n"26962026/10/01 08:35:27 WARN Failed to register uploaded object key=s98hz2spkwy2ix0cdzdwjaxy7lm420kc.narinfo error="server returned 404: 404 page not found\n"26972026/10/01 08:35:27 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)26982026/10/01 08:35:27 OK 20260905000000_add_claims.sql (2.86ms)26992026/10/01 08:35:27 INFO All 1 paths already cached27002026/10/01 08:35:27 OK 20260920000000_drop_claims.sql (1.63ms)2701=== NAME TestClientIntegration2702 client_integration_test.go:312: Retrieved narinfo from S3:2703 StorePath: /build/TestClientIntegration3913055656/002/store/5kimq7zq1229n6fz2j1a36i2k7vxshif-test-file.txt2704 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2705 Compression: zstd2706 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12707 NarSize: 1522708 References: 2709 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk127102026/10/01 08:35:27 OK 20260923120000_add_pushes.sql (1.43ms)27112026/10/01 08:35:27 goose: successfully migrated database to version: 202609231200002712 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)27132026/10/01 08:35:27 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=02714 client_integration_test.go:313: Decompressed .ls content (64 bytes):2715 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2716 client_integration_test.go:316: Testing garbage collection...27172026/10/01 08:35:27 INFO Upload complete. (65ms)2718=== NAME TestClientMultipleUploads2719 client_integration_test.go:369: Uploaded 3 paths in 115.089935ms27202026/10/01 08:35:27 OK 1_commit_pending_closure.sql (1.84ms)2721=== NAME TestClientCADerivations27222026/10/01 08:35:27 OK 2_object_stats_trigger.sql (912.61µs)2723 client_ca_test.go:139: Found 1 dependencies (including self)27242026/10/01 08:35:27 INFO Vacuumed table table=pending_closures27252026/10/01 08:35:27 OK 3_commit_push.sql (723.28µs)27262026/10/01 08:35:27 goose: up to current file version: 327272026/10/01 08:35:27 INFO Vacuumed table table=pending_objects27282026/10/01 08:35:27 INFO Vacuumed table table=multipart_uploads2729--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.48s)27302026/10/01 08:35:27 INFO Vacuumed table table=closures27312026/10/01 08:35:27 INFO Vacuumed table table=objects2732--- PASS: TestClientMultipleUploads (0.83s)27332026/10/01 08:35:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"27342026/10/01 08:35:27 WARN mTLS auth: bound subjects configured but subject DN unavailable27352026/10/01 08:35:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2736--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.47s)27372026/10/01 08:35:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures27382026/10/01 08:35:27 INFO Garbage collection started27392026/10/01 08:35:27 INFO Aborted multipart uploads count=027402026/10/01 08:35:27 WARN Force mode enabled - objects will be deleted immediately without grace period27412026/10/01 08:35:27 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=027422026/10/01 08:35:27 INFO Vacuumed table table=pending_closures2743=== RUN TestService_RequireScope_OIDC/builder_may_write2744=== PAUSE TestService_RequireScope_OIDC/builder_may_write2745=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2746=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2747=== RUN TestService_RequireScope_OIDC/ops_may_admin2748=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2749=== RUN TestService_RequireScope_OIDC/ops_may_not_write2750=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2751=== RUN TestService_RequireScope_OIDC/reader_may_not_write2752=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2753=== RUN TestService_RequireScope_OIDC/static_token_may_admin2754=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2755=== RUN TestService_RequireScope_OIDC/static_token_may_write2756=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2757=== RUN TestService_RequireScope_OIDC/reader_may_read2758=== PAUSE TestService_RequireScope_OIDC/reader_may_read2759=== RUN TestService_RequireScope_OIDC/writer_implies_read2760=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2761=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2762=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2763=== CONT TestService_RequireScope_OIDC/builder_may_write2764=== CONT TestService_RequireScope_OIDC/reader_may_not_write27652026/10/01 08:35:27 INFO Vacuumed table table=pending_objects2766=== CONT TestService_RequireScope_OIDC/static_token_may_admin2767=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2768=== CONT TestService_RequireScope_OIDC/ops_may_admin27692026/10/01 08:35:27 INFO Vacuumed table table=multipart_uploads2770=== CONT TestService_RequireScope_OIDC/reader_may_read2771=== CONT TestService_RequireScope_OIDC/writer_implies_read2772=== CONT TestService_RequireScope_OIDC/static_token_may_write2773=== CONT TestService_RequireScope_OIDC/ops_may_not_write2774=== CONT TestService_RequireScope_OIDC/builder_may_not_admin27752026/10/01 08:35:27 INFO Vacuumed table table=closures2776--- PASS: TestService_RequireScope_OIDC (0.61s)2777 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2778 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2779 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2780 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2781 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2782 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2783 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2784 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2785 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2786 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)27872026/10/01 08:35:27 INFO Vacuumed table table=objects2788--- PASS: TestMetricsInventory (0.44s)2789--- PASS: TestService_ReadAuthMiddleware (0.40s)27902026/10/01 08:35:27 INFO Received cleanup request method=DELETE path=/api/pending_closures27912026/10/01 08:35:27 INFO Aborted multipart uploads count=12792--- PASS: TestMultipartCleanup (0.61s)27932026/10/01 08:35:27 INFO Received push request method=POST path=/api/pushes27942026/10/01 08:35:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27952026/10/01 08:35:27 INFO Uploading sqcspvhvvjhl7kdp5gzddrng6nsln1k2-ca-test (144B)27962026/10/01 08:35:27 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"27972026/10/01 08:35:27 WARN Failed to register uploaded object key=sqcspvhvvjhl7kdp5gzddrng6nsln1k2.ls error="server returned 404: 404 page not found\n"27982026/10/01 08:35:27 WARN Failed to register uploaded object key=log/q3aimvv680asrh6mml07x6xw9h3aglln-ca-test.drv error="server returned 404: 404 page not found\n"27992026/10/01 08:35:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28002026/10/01 08:35:27 INFO Signed narinfos id=1 count=128012026/10/01 08:35:27 INFO Uploading 1 narinfos28022026/10/01 08:35:27 INFO Received complete push request method=POST path=/api/pushes/1/complete28032026/10/01 08:35:27 WARN Failed to register uploaded object key=sqcspvhvvjhl7kdp5gzddrng6nsln1k2.narinfo error="server returned 404: 404 page not found\n"28042026/10/01 08:35:27 INFO Upload complete. (98ms)2805=== NAME TestClientCADerivations2806 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2181080612/001/store/sqcspvhvvjhl7kdp5gzddrng6nsln1k2-ca-test2807 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2808 Compression: zstd2809 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2810 NarSize: 1442811 References: 2812 Deriver: /build/TestClientCADerivations2181080612/001/store/q3aimvv680asrh6mml07x6xw9h3aglln-ca-test.drv2813 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2814 client_ca_test.go:185: Checking for realisation files in S3...2815=== NAME TestOrphanedObjectsGC2816 orphaned_objects_gc_test.go:290: GC Test Summary:2817 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2818 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2819 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2820 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2821 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2822--- PASS: TestOrphanedObjectsGC (0.93s)2823=== NAME TestClientCADerivations2824 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2825 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2826=== NAME TestNARDeduplicationMetadataUploadBug2827 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1534316014/001/store/8khqxsmwcr8x4f0kwbdjlagvd96411d3-file1.txt28282026/10/01 08:35:27 INFO Received uploads request method=POST path=/api/pending_closures28292026/10/01 08:35:28 INFO Aborted multipart uploads count=028302026/10/01 08:35:28 WARN Force mode enabled - objects will be deleted immediately without grace period28312026/10/01 08:35:28 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=028322026/10/01 08:35:28 INFO Vacuumed table table=pending_closures28332026/10/01 08:35:28 INFO Vacuumed table table=pending_objects28342026/10/01 08:35:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.914295ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28352026/10/01 08:35:28 INFO Vacuumed table table=multipart_uploads28362026/10/01 08:35:28 INFO Vacuumed table table=closures28372026/10/01 08:35:28 INFO Received uploads request method=POST path=/api/pending_closures28382026/10/01 08:35:28 INFO Vacuumed table table=objects28392026/10/01 08:35:28 INFO Aborted multipart uploads count=028402026/10/01 08:35:28 WARN Force mode enabled - objects will be deleted immediately without grace period28412026/10/01 08:35:28 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=028422026/10/01 08:35:28 INFO Vacuumed table table=pending_closures28432026/10/01 08:35:28 INFO Vacuumed table table=pending_objects28442026/10/01 08:35:28 INFO Vacuumed table table=multipart_uploads28452026/10/01 08:35:28 INFO Vacuumed table table=closures28462026/10/01 08:35:28 INFO Vacuumed table table=objects2847--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2848 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)2849 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.40s)28502026/10/01 08:35:28 INFO Received push request method=POST path=/api/pushes28512026/10/01 08:35:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)28522026/10/01 08:35:28 INFO Uploading 8khqxsmwcr8x4f0kwbdjlagvd96411d3-file1.txt (160B)28532026/10/01 08:35:28 WARN Failed to register uploaded object key=8khqxsmwcr8x4f0kwbdjlagvd96411d3.ls error="server returned 404: 404 page not found\n"28542026/10/01 08:35:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28552026/10/01 08:35:28 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"28562026/10/01 08:35:28 INFO Signed narinfos id=1 count=128572026/10/01 08:35:28 INFO Uploading 1 narinfos28582026/10/01 08:35:28 INFO Received complete push request method=POST path=/api/pushes/1/complete28592026/10/01 08:35:28 WARN Failed to register uploaded object key=8khqxsmwcr8x4f0kwbdjlagvd96411d3.narinfo error="server returned 404: 404 page not found\n"28602026/10/01 08:35:28 INFO Upload complete. (53ms)2861=== NAME TestNARDeduplicationMetadataUploadBug2862 metadata_upload_test.go:54: Retrieved narinfo from S3:2863 StorePath: /build/TestNARDeduplicationMetadataUploadBug1534316014/001/store/8khqxsmwcr8x4f0kwbdjlagvd96411d3-file1.txt2864 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2865 Compression: zstd2866 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2867 NarSize: 1602868 References: 2869 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2870 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2871 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2872 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2873 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1534316014/001/store/29kzj31y23qyv406cqr6nbd2inpdm2wk-file2.txt2874=== NAME TestClientCADerivations2875 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2876 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable28772026/10/01 08:35:28 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2878 error: binary cache 's3://bucket64?endpoint=http://localhost:46793®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2181080612/001/store'2879 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12880--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2881 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2882 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2883 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.57s)2884--- PASS: TestClientCADerivations (1.09s)28852026/10/01 08:35:28 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28862026/10/01 08:35:28 INFO Received push request method=POST path=/api/pushes28872026/10/01 08:35:28 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)28882026/10/01 08:35:28 WARN Failed to register uploaded object key=29kzj31y23qyv406cqr6nbd2inpdm2wk.ls error="server returned 404: 404 page not found\n"28892026/10/01 08:35:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign28902026/10/01 08:35:28 INFO Signed narinfos id=2 count=128912026/10/01 08:35:28 INFO Uploading 1 narinfos28922026/10/01 08:35:28 INFO Received complete push request method=POST path=/api/pushes/2/complete28932026/10/01 08:35:28 WARN Failed to register uploaded object key=29kzj31y23qyv406cqr6nbd2inpdm2wk.narinfo error="server returned 404: 404 page not found\n"28942026/10/01 08:35:28 INFO Upload complete. (50ms)2895=== NAME TestNARDeduplicationMetadataUploadBug2896 metadata_upload_test.go:76: Retrieved narinfo from S3:2897 StorePath: /build/TestNARDeduplicationMetadataUploadBug1534316014/001/store/29kzj31y23qyv406cqr6nbd2inpdm2wk-file2.txt2898 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2899 Compression: zstd2900 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2901 NarSize: 1602902 References: 2903 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2904 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2905 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2906 {"version":1,"root":{"type":"regular","size":44}}2907--- PASS: TestNARDeduplicationMetadataUploadBug (0.68s)29082026/10/01 08:35:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.460361ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2909=== NAME TestOrphanedObjectsGCStressTest2910 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2911 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion29122026/10/01 08:35:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.741106958s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2913 orphaned_objects_gc_test.go:509: Stress test completed successfully:2914 orphaned_objects_gc_test.go:510: - Active objects preserved: 202915 orphaned_objects_gc_test.go:511: - Objects deleted: 2102916 orphaned_objects_gc_test.go:512: - Total GC'd: 2102917--- PASS: TestOrphanedObjectsGCStressTest (2.44s)29182026/10/01 08:35:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02919=== NAME TestPinProtectsFromGC2920 client_integration_test.go:794: Pin successfully protected closure from garbage collection2921--- PASS: TestPinProtectsFromGC (2.94s)29222026/10/01 08:35:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02923=== NAME TestClientIntegration2924 client_integration_test.go:323: Objects in database after GC:2925 client_integration_test.go:323: Successfully deleted all objects with GC --force2926--- PASS: TestClientIntegration (2.84s)29272026/10/01 08:35:29 WARN Rate limiter enabled after throttle name=s3-test rate=529282026/10/01 08:35:29 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2929=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2930 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102931 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002932--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.25s)29332026/10/01 08:35:30 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-config29342026/10/01 08:35:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.467388ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29352026/10/01 08:35:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.574619ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29362026/10/01 08:35:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=840.094365ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29372026/10/01 08:35:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.474182688s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29382026/10/01 08:35:33 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"29392026/10/01 08:35:33 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-config29402026/10/01 08:35:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.85461ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29412026/10/01 08:35:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.724637ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29422026/10/01 08:35:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=827.080507ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29432026/10/01 08:35:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.738947237s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29442026/10/01 08:35:37 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_closures29452026/10/01 08:35:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.398166ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29462026/10/01 08:35:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.372887ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29472026/10/01 08:35:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=829.064279ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29482026/10/01 08:35:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.751933164s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2949--- PASS: TestClientErrorHandling (0.00s)2950 --- PASS: TestClientErrorHandling/InvalidStorePath (0.35s)2951 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.47s)2952 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.82s)2953PASS29542026-10-01 08:35:40.765 UTC [131] LOG: received smart shutdown request29552026-10-01 08:35:40.770 UTC [131] LOG: background worker "logical replication launcher" (PID 141) exited with exit code 129562026-10-01 08:35:40.774 UTC [136] LOG: shutting down29572026-10-01 08:35:40.776 UTC [136] LOG: checkpoint starting: shutdown immediate29582026-10-01 08:35:42.217 UTC [136] LOG: checkpoint complete: wrote 10603 buffers (64.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 22 recycled; write=0.268 s, sync=1.136 s, total=1.443 s; sync files=26627, longest=0.007 s, average=0.001 s; distance=362318 kB, estimate=362318 kB; lsn=0/17939860, redo lsn=0/1793986029592026-10-01 08:35:42.285 UTC [131] LOG: database system is shut down2960Running OIDC tests...2961=== RUN TestAudienceForIssuer2962=== PAUSE TestAudienceForIssuer2963=== RUN TestGlobMatch2964=== PAUSE TestGlobMatch2965=== RUN TestValidateToken_ValidToken2966=== PAUSE TestValidateToken_ValidToken2967=== RUN TestValidateToken_WrongAudience2968=== PAUSE TestValidateToken_WrongAudience2969=== RUN TestValidateToken_Expired2970=== PAUSE TestValidateToken_Expired2971=== RUN TestValidateToken_BoundClaimsMismatch2972=== PAUSE TestValidateToken_BoundClaimsMismatch2973=== RUN TestValidateToken_BoundSubjectMismatch2974=== PAUSE TestValidateToken_BoundSubjectMismatch2975=== RUN TestValidateToken_MultipleProviders2976=== PAUSE TestValidateToken_MultipleProviders2977=== RUN TestValidateToken_NoMatchingProvider2978=== PAUSE TestValidateToken_NoMatchingProvider2979=== RUN TestValidateToken_KubernetesServiceAccount2980=== PAUSE TestValidateToken_KubernetesServiceAccount2981=== RUN TestNewValidator_KubernetesRequiresCA2982=== PAUSE TestNewValidator_KubernetesRequiresCA2983=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2984=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2985=== RUN TestPins_ReservedForMatchingRule2986=== PAUSE TestPins_ReservedForMatchingRule2987=== RUN TestPins_TopLevelShorthand2988=== PAUSE TestPins_TopLevelShorthand2989=== RUN TestPins_ConfigValidation2990=== PAUSE TestPins_ConfigValidation2991=== RUN TestScopes_LegacyProviderDefaultsToWrite2992=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2993=== RUN TestScopes_Rules2994=== PAUSE TestScopes_Rules2995=== RUN TestScopes_ConfigValidation2996=== PAUSE TestScopes_ConfigValidation2997=== CONT TestAudienceForIssuer2998=== CONT TestValidateToken_KubernetesServiceAccount2999=== CONT TestPins_ConfigValidation3000=== CONT TestScopes_ConfigValidation3001=== CONT TestScopes_Rules3002=== CONT TestScopes_LegacyProviderDefaultsToWrite3003=== CONT TestValidateToken_BoundClaimsMismatch3004=== CONT TestValidateToken_NoMatchingProvider3005=== CONT TestValidateToken_MultipleProviders3006--- PASS: TestAudienceForIssuer (0.00s)3007=== CONT TestValidateToken_Expired3008--- PASS: TestScopes_ConfigValidation (0.00s)3009=== CONT TestValidateToken_BoundSubjectMismatch3010=== CONT TestPins_ReservedForMatchingRule3011=== CONT TestValidateToken_WrongAudience3012=== CONT TestValidateToken_ValidToken3013=== CONT TestPins_TopLevelShorthand3014=== CONT TestGlobMatch3015=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3016=== CONT TestNewValidator_KubernetesRequiresCA3017--- PASS: TestPins_ConfigValidation (0.00s)3018=== RUN TestGlobMatch/foo_foo3019=== PAUSE TestGlobMatch/foo_foo3020=== RUN TestGlobMatch/foo_bar3021=== PAUSE TestGlobMatch/foo_bar3022=== RUN TestGlobMatch/*_3023=== PAUSE TestGlobMatch/*_3024=== RUN TestGlobMatch/*_anything3025=== PAUSE TestGlobMatch/*_anything3026=== RUN TestGlobMatch/foo*_foo3027=== PAUSE TestGlobMatch/foo*_foo3028=== RUN TestGlobMatch/foo*_foobar3029=== PAUSE TestGlobMatch/foo*_foobar3030=== RUN TestGlobMatch/foo*_bar3031=== PAUSE TestGlobMatch/foo*_bar3032=== RUN TestGlobMatch/*bar_bar3033=== PAUSE TestGlobMatch/*bar_bar3034=== RUN TestGlobMatch/*bar_foobar3035=== PAUSE TestGlobMatch/*bar_foobar3036=== RUN TestGlobMatch/*bar_foo3037=== PAUSE TestGlobMatch/*bar_foo3038=== RUN TestGlobMatch/foo*bar_foobar3039=== PAUSE TestGlobMatch/foo*bar_foobar3040=== RUN TestGlobMatch/foo*bar_foo123bar3041=== PAUSE TestGlobMatch/foo*bar_foo123bar3042=== RUN TestGlobMatch/foo*bar_foobarbaz3043=== PAUSE TestGlobMatch/foo*bar_foobarbaz3044=== RUN TestGlobMatch/*/*_foo/bar3045=== PAUSE TestGlobMatch/*/*_foo/bar3046=== RUN TestGlobMatch/*/*_foo3047=== PAUSE TestGlobMatch/*/*_foo3048=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3049=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3050=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03051=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03052=== RUN TestGlobMatch/refs/*/main_refs/heads/main3053=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3054=== RUN TestGlobMatch/fo?_foo3055=== PAUSE TestGlobMatch/fo?_foo3056=== RUN TestGlobMatch/fo?_fo3057=== PAUSE TestGlobMatch/fo?_fo3058=== RUN TestGlobMatch/fo?_fooo3059=== PAUSE TestGlobMatch/fo?_fooo3060=== RUN TestGlobMatch/?oo_foo3061=== PAUSE TestGlobMatch/?oo_foo3062=== RUN TestGlobMatch/?oo_boo3063=== PAUSE TestGlobMatch/?oo_boo3064=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3065=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3066=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3067=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3068=== CONT TestGlobMatch/foo_foo3069=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3070=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3071=== CONT TestGlobMatch/?oo_boo3072=== CONT TestGlobMatch/?oo_foo3073=== CONT TestGlobMatch/fo?_fooo3074=== CONT TestGlobMatch/fo?_fo3075=== CONT TestGlobMatch/fo?_foo3076=== CONT TestGlobMatch/refs/*/main_refs/heads/main3077=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03078=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3079=== CONT TestGlobMatch/*/*_foo3080=== CONT TestGlobMatch/*/*_foo/bar3081=== CONT TestGlobMatch/foo*bar_foobarbaz3082=== CONT TestGlobMatch/foo*bar_foo123bar3083=== CONT TestGlobMatch/foo*bar_foobar3084=== CONT TestGlobMatch/*bar_foo3085=== CONT TestGlobMatch/*bar_foobar3086=== CONT TestGlobMatch/*bar_bar3087=== CONT TestGlobMatch/foo*_bar3088=== CONT TestGlobMatch/foo*_foobar3089=== CONT TestGlobMatch/foo*_foo3090=== CONT TestGlobMatch/*_anything3091=== CONT TestGlobMatch/*_3092=== CONT TestGlobMatch/foo_bar3093--- PASS: TestGlobMatch (0.00s)3094 --- PASS: TestGlobMatch/foo_foo (0.00s)3095 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3096 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3097 --- PASS: TestGlobMatch/?oo_boo (0.00s)3098 --- PASS: TestGlobMatch/?oo_foo (0.00s)3099 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3100 --- PASS: TestGlobMatch/fo?_fo (0.00s)3101 --- PASS: TestGlobMatch/fo?_foo (0.00s)3102 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3103 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3104 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3105 --- PASS: TestGlobMatch/*/*_foo (0.00s)3106 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3107 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3108 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3109 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3110 --- PASS: TestGlobMatch/*bar_foo (0.00s)3111 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3112 --- PASS: TestGlobMatch/*bar_bar (0.00s)3113 --- PASS: TestGlobMatch/foo*_bar (0.00s)3114 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3115 --- PASS: TestGlobMatch/foo*_foo (0.00s)3116 --- PASS: TestGlobMatch/*_anything (0.00s)3117 --- PASS: TestGlobMatch/*_ (0.00s)3118 --- PASS: TestGlobMatch/foo_bar (0.00s)31192026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37815/oidc3120--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)31212026/10/01 08:35:43 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38429/oidc31222026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46823/oidc3123--- PASS: TestValidateToken_NoMatchingProvider (0.03s)3124--- PASS: TestPins_ReservedForMatchingRule (0.03s)31252026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33511/oidc31262026/10/01 08:35:43 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3977531272026/10/01 08:35:43 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233128--- PASS: TestValidateToken_Expired (0.05s)3129--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)31302026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33065/oidc3131--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)3132--- PASS: TestValidateToken_ValidToken (0.04s)31332026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41975/oidc3134--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)31352026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43645/oidc3136--- PASS: TestValidateToken_WrongAudience (0.05s)31372026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43141/oidc3138--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)31392026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42287/oidc31402026/10/01 08:35:43 http: TLS handshake error from 127.0.0.1:50264: remote error: tls: bad certificate3141--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)3142--- PASS: TestScopes_Rules (0.08s)31432026/10/01 08:35:43 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41015/oidc31442026/10/01 08:35:43 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34839/oidc3145--- PASS: TestValidateToken_MultipleProviders (0.09s)31462026/10/01 08:35:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35757/oidc3147--- PASS: TestPins_TopLevelShorthand (0.09s)3148PASS3149Running hook tests...3150=== RUN TestSendPathsEmpty3151=== PAUSE TestSendPathsEmpty3152=== RUN TestQueueEnqueueAndFetch3153=== PAUSE TestQueueEnqueueAndFetch3154=== RUN TestQueueDeduplication3155=== PAUSE TestQueueDeduplication3156=== RUN TestQueueRemove3157=== PAUSE TestQueueRemove3158=== RUN TestQueueFetchBatchLimit3159=== PAUSE TestQueueFetchBatchLimit3160=== RUN TestQueueRetryMovesToBack3161=== PAUSE TestQueueRetryMovesToBack3162=== RUN TestQueueFetchRemoveLifecycle3163=== PAUSE TestQueueFetchRemoveLifecycle3164=== RUN TestQueueConcurrentWriters3165=== PAUSE TestQueueConcurrentWriters3166=== RUN TestQueueRemoveLargeClosure3167=== PAUSE TestQueueRemoveLargeClosure3168=== RUN TestServerClientIntegration3169=== PAUSE TestServerClientIntegration3170=== RUN TestServerQueueError3171=== PAUSE TestServerQueueError3172=== RUN TestGetListenerSocketActivation3173 server_test.go:210: === RUN TestGetListenerSocketActivation3174 --- PASS: TestGetListenerSocketActivation (0.00s)3175 PASS3176 3177--- PASS: TestGetListenerSocketActivation (0.00s)3178=== RUN TestDrainIsolatesPoisonPath3179=== PAUSE TestDrainIsolatesPoisonPath3180=== RUN TestRunNotBlockedByPoisonHead3181=== PAUSE TestRunNotBlockedByPoisonHead3182=== RUN TestDrainGivesUpWhenServerDown3183=== PAUSE TestDrainGivesUpWhenServerDown3184=== RUN TestFailedPathPrunedByLaterClosure3185=== PAUSE TestFailedPathPrunedByLaterClosure3186=== RUN TestWorkerUploadsAndRemoves3187=== PAUSE TestWorkerUploadsAndRemoves3188=== RUN TestWorkerSkipsGCdPaths3189=== PAUSE TestWorkerSkipsGCdPaths3190=== RUN TestWorkerPrunesClosureDeps3191=== PAUSE TestWorkerPrunesClosureDeps3192=== RUN TestDrainTimeout3193=== PAUSE TestDrainTimeout3194=== CONT TestSendPathsEmpty3195=== CONT TestServerQueueError3196=== CONT TestDrainGivesUpWhenServerDown3197--- PASS: TestSendPathsEmpty (0.00s)3198=== CONT TestServerClientIntegration3199=== CONT TestQueueRemoveLargeClosure3200=== CONT TestQueueConcurrentWriters32012026/10/01 08:35:44 ERROR Failed to queue paths error="permission denied" count=13202=== CONT TestQueueFetchRemoveLifecycle3203=== CONT TestQueueRetryMovesToBack3204--- PASS: TestServerQueueError (0.00s)3205=== CONT TestQueueFetchBatchLimit3206=== CONT TestQueueRemove3207=== CONT TestWorkerUploadsAndRemoves3208=== CONT TestQueueDeduplication3209=== CONT TestDrainTimeout3210=== CONT TestWorkerPrunesClosureDeps3211=== CONT TestQueueEnqueueAndFetch3212=== CONT TestWorkerSkipsGCdPaths3213=== CONT TestFailedPathPrunedByLaterClosure3214=== CONT TestRunNotBlockedByPoisonHead3215=== CONT TestDrainIsolatesPoisonPath3216--- PASS: TestServerClientIntegration (0.00s)32172026/10/01 08:35:44 INFO Upload queue status pending=232182026/10/01 08:35:44 INFO Uploading batch count=232192026/10/01 08:35:44 INFO Uploading batch count=232202026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=232212026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3088455165/002/a32222026/10/01 08:35:44 INFO Upload queue status pending=232232026/10/01 08:35:44 INFO Uploading batch count=232242026/10/01 08:35:44 INFO Upload queue status pending=232252026/10/01 08:35:44 INFO Upload queue status pending=332262026/10/01 08:35:44 INFO Uploading batch count=432272026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=432282026/10/01 08:35:44 INFO Uploading batch count=132292026/10/01 08:35:44 INFO Uploading batch count=13230--- PASS: TestQueueRemove (0.02s)32312026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=132322026/10/01 08:35:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4041406333/002/nonexistent32332026/10/01 08:35:44 INFO Uploading batch count=132342026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=13235--- PASS: TestQueueFetchBatchLimit (0.02s)32362026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3088455165/002/b3237--- PASS: TestQueueDeduplication (0.02s)32382026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath507608577/002/bbb3239--- PASS: TestQueueRetryMovesToBack (0.02s)32402026/10/01 08:35:44 INFO Uploading batch count=132412026/10/01 08:35:44 INFO Uploading batch count=232422026/10/01 08:35:44 INFO Uploading batch count=13243--- PASS: TestQueueEnqueueAndFetch (0.02s)32442026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=23245--- PASS: TestQueueFetchRemoveLifecycle (0.03s)32462026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3088455165/002/c32472026/10/01 08:35:44 INFO Uploading batch count=132482026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3088455165/002/d32492026/10/01 08:35:44 INFO Uploading batch count=132502026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=132512026/10/01 08:35:44 INFO Uploading batch count=232522026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=232532026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3088455165/002/e32542026/10/01 08:35:44 INFO Uploading batch count=132552026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=132562026/10/01 08:35:44 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3088455165/002/f32572026/10/01 08:35:44 INFO Uploading batch count=132582026/10/01 08:35:44 ERROR Upload failed error="upload failed" count=13259--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)32602026/10/01 08:35:44 ERROR Drain finished with paths left in queue remaining=132612026/10/01 08:35:44 ERROR Drain finished with paths left in queue remaining=103262--- PASS: TestDrainIsolatesPoisonPath (0.03s)3263--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3264--- PASS: TestWorkerSkipsGCdPaths (0.04s)3265--- PASS: TestWorkerUploadsAndRemoves (0.04s)3266--- PASS: TestWorkerPrunesClosureDeps (0.04s)3267--- PASS: TestQueueRemoveLargeClosure (0.09s)32682026/10/01 08:35:44 ERROR Upload failed error="context deadline exceeded" count=232692026/10/01 08:35:44 ERROR Drain finished with paths left in queue remaining=43270--- PASS: TestDrainTimeout (0.22s)3271--- PASS: TestQueueConcurrentWriters (0.39s)32722026/10/01 08:35:45 INFO Uploading batch count=132732026/10/01 08:35:45 INFO Uploading batch count=132742026/10/01 08:35:45 INFO Uploading batch count=132752026/10/01 08:35:45 ERROR Upload failed error="upload failed" count=132762026/10/01 08:35:45 INFO Uploading batch count=132772026/10/01 08:35:45 ERROR Upload failed error="upload failed" count=132782026/10/01 08:35:45 INFO Uploading batch count=132792026/10/01 08:35:45 ERROR Upload failed error="upload failed" count=132802026/10/01 08:35:45 INFO Uploading batch count=132812026/10/01 08:35:45 ERROR Upload failed error="upload failed" count=132822026/10/01 08:35:45 ERROR Drain finished with paths left in queue remaining=13283--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3284PASS