niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #315
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestShellSplit98=== CONT TestScriptTokenBadJSON99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestScriptTokenEmptyCommand101=== CONT TestResolveStorePath102=== CONT TestScriptTokenEmptyToken103=== CONT TestScriptTokenCachesUntilRefresh104=== CONT TestScriptTokenNoExpiryRerunsEveryCall105=== CONT TestFileTokenEmpty106=== CONT TestFileTokenMissing107=== CONT TestFileTokenReadsAndCaches108=== CONT TestStaticToken109=== CONT TestRateLimiterFeedback110=== CONT TestSetClientTLSErrors111=== CONT TestSetClientTLSDoesNotMutateDefaultTransport112=== CONT TestParsePathInfoJSON113=== RUN TestParsePathInfoJSON/Nix_format114=== PAUSE TestParsePathInfoJSON/Nix_format115=== CONT TestSetClientTLS116=== CONT TestClientSignaturesByStorePath117=== CONT TestStreamPushReportsSignatures118=== CONT TestStreamPushRequestLine119=== CONT TestStreamPushGivesUpOnDeadServer120=== CONT TestStreamPushIsolatesFailures121=== CONT TestStreamPushBatchesUnderLoad122=== CONT TestStreamPushReportsEveryPath123=== CONT TestShellSplitErrors124--- PASS: TestShellSplit (0.00s)125=== CONT TestEncodeNixBase32WithRealHash126=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess127=== RUN TestRateLimiterFeedback/429_enables_limiter128=== PAUSE TestRateLimiterFeedback/429_enables_limiter129=== RUN TestRateLimiterFeedback/503_enables_limiter1302026/10/01 09:42:10 WARN Rate limiter enabled after throttle name=server-test rate=51312026/10/01 09:42:10 ERROR Upload failed error="connection refused" count=201322026/10/01 09:42:10 ERROR Server seems unavailable, giving up on batch untried=17133=== CONT TestPathInfoCACompatibility134=== RUN TestPathInfoCACompatibility/null_ca_field1352026/10/01 09:42:10 ERROR Upload failed error="bad path" count=3136--- PASS: TestScriptTokenEmptyCommand (0.00s)137=== CONT TestParsePathInfoJSONMultiplePaths138=== CONT TestPathInfoHashCompatibility139=== RUN TestParsePathInfoJSON/Lix_format140=== CONT TestGetStorePathHash141=== PAUSE TestRateLimiterFeedback/503_enables_limiter142=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter143=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter144=== CONT TestDumpPathWriterError145=== CONT TestFilterOversizedClosures146=== RUN TestGetStorePathHash/valid_store_path1472026/10/01 09:42:10 ERROR Upload failed error=boom count=1148=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== CONT TestDumpPathMatchesNix1502026/10/01 09:42:10 ERROR Upload failed error=boom count=1151=== CONT TestUploadMultipart_SupersededByPeer152=== RUN TestUploadMultipart_SupersededByPeer/exists1532026/10/01 09:42:10 WARN Rate limiter enabled after throttle name=server-test rate=51542026/10/01 09:42:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33813155=== RUN TestFilterOversizedClosures/no_limit_keeps_everything156=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths157=== CONT TestEncodeNixBase32158=== CONT TestConvertHashToNix32159=== PAUSE TestPathInfoCACompatibility/null_ca_field160--- PASS: TestScriptTokenScriptFails (0.00s)161--- PASS: TestStaticToken (0.00s)162=== PAUSE TestParsePathInfoJSON/Lix_format163=== CONT TestDumpPathSingleFile1642026/10/01 09:42:10 WARN Rate limiter backed off name=server-test rate=51652026/10/01 09:42:10 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33813166=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter167=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== PAUSE TestGetStorePathHash/valid_store_path169=== PAUSE TestUploadMultipart_SupersededByPeer/exists170=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything171--- PASS: TestFileTokenMissing (0.00s)172=== RUN TestSetClientTLS/rejects_connection_without_client_cert173--- PASS: TestScriptTokenBadJSON (0.00s)174--- PASS: TestResolveStorePath (0.00s)175=== RUN TestEncodeNixBase32/test_string_hash176=== CONT TestCaseHackSuffix177=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths178=== RUN TestConvertHashToNix32/SRI_format_to_Nix32179=== RUN TestPathInfoCACompatibility/old_string_format_-_text180=== RUN TestParsePathInfoJSON/empty_input181=== CONT TestPartSizeForNAR182=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter183=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)184=== RUN TestGetStorePathHash/basename_without_hyphen_should_error185=== RUN TestUploadMultipart_SupersededByPeer/missing186=== CONT TestUploadMultipart_PartsInParallel187=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped188=== CONT TestRegisterUploadedObjectReusesConnections189=== RUN TestSetClientTLSErrors/missing_cert_file190=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert191--- PASS: TestFileTokenEmpty (0.00s)192=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text193=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive194--- PASS: TestClientSignaturesByStorePath (0.00s)195--- PASS: TestShellSplitErrors (0.00s)196--- PASS: TestFileTokenReadsAndCaches (0.00s)197--- PASS: TestEncodeNixBase32WithRealHash (0.00s)198=== CONT TestRateLimiterFeedback/429_enables_limiter199=== PAUSE TestParsePathInfoJSON/empty_input200=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped202=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32203=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon204=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon205=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA206=== PAUSE TestUploadMultipart_SupersededByPeer/missing207=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error208=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error209=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error210=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths211=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI212=== RUN TestPartSizeForNAR/zero_stays_at_minimum213=== RUN TestParsePathInfoJSON/whitespace_only214=== PAUSE TestSetClientTLSErrors/missing_cert_file215=== PAUSE TestEncodeNixBase32/test_string_hash216=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive217--- PASS: TestScriptTokenEmptyToken (0.00s)218--- PASS: TestStreamPushIsolatesFailures (0.00s)219--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)220--- PASS: TestStreamPushReportsSignatures (0.00s)221--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)222--- PASS: TestStreamPushReportsEveryPath (0.00s)223--- PASS: TestDoServerRequestAttachesToken (0.01s)224=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter225=== RUN TestPathInfoCACompatibility/new_structured_format_-_text226=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text227=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2282026/10/01 09:42:10 WARN Rate limiter enabled after throttle name=server-test rate=5229=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method2302026/10/01 09:42:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:32921231--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)232--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)233--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)234=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA235=== RUN TestSetClientTLS/preserves_debug_logging_transport236=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2372026/10/01 09:42:10 WARN Rate limiter backed off name=server-test rate=5238=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error239=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error240=== CONT TestRateLimiterFeedback/503_enables_limiter241=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter242=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI243=== RUN TestConvertHashToNix32/already_Nix32_format244=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum245=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths246=== PAUSE TestParsePathInfoJSON/whitespace_only247=== RUN TestSetClientTLSErrors/missing_key_file248=== RUN TestEncodeNixBase32/empty_input249--- PASS: TestCaseHackSuffix (0.04s)250=== CONT TestPathInfoCACompatibility/null_ca_field251=== RUN TestFilterOversizedClosures/all_closures_skipped252=== PAUSE TestFilterOversizedClosures/all_closures_skipped253=== CONT TestUploadMultipart_SupersededByPeer/missing254=== CONT TestSetClientTLS/rejects_connection_without_client_cert255=== RUN TestParsePathInfoJSON/invalid_JSON256=== PAUSE TestSetClientTLSErrors/missing_key_file257=== RUN TestSetClientTLSErrors/missing_ca_file258=== PAUSE TestSetClientTLSErrors/missing_ca_file259=== RUN TestSetClientTLSErrors/invalid_ca_file260=== PAUSE TestSetClientTLSErrors/invalid_ca_file261=== PAUSE TestEncodeNixBase32/empty_input262=== PAUSE TestParsePathInfoJSON/invalid_JSON263=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA264--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)265 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)266 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)2672026/10/01 09:42:10 WARN Rate limiter enabled after throttle name=server-test rate=5268=== CONT TestPathInfoCACompatibility/old_string_format_-_text269=== CONT TestUploadMultipart_SupersededByPeer/exists2702026/10/01 09:42:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39203271=== CONT TestGetStorePathHash/valid_store_path272=== CONT TestPathInfoCACompatibility/new_structured_format_-_text273=== CONT TestFilterOversizedClosures/no_limit_keeps_everything274=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method275=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error276=== CONT TestSetClientTLSErrors/missing_cert_file277=== CONT TestEncodeNixBase32/test_string_hash278=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive279=== RUN TestPartSizeForNAR/small_stays_at_minimum280=== PAUSE TestPartSizeForNAR/small_stays_at_minimum281=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum282=== PAUSE TestConvertHashToNix32/already_Nix32_format283=== CONT TestParsePathInfoJSON/Nix_format284--- PASS: TestDumpPathSingleFile (0.04s)285=== CONT TestSetClientTLS/preserves_debug_logging_transport286=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error287=== CONT TestGetStorePathHash/basename_without_hyphen_should_error2882026/10/01 09:42:10 WARN Rate limiter backed off name=server-test rate=5289=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum291=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts292=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts293=== CONT TestSetClientTLSErrors/missing_ca_file294=== CONT TestSetClientTLSErrors/missing_key_file295--- PASS: TestRateLimiterFeedback (0.01s)296 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.03s)297 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)298 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)300=== CONT TestParsePathInfoJSON/empty_input301--- PASS: TestGetStorePathHash (0.04s)302 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)303 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)304 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306=== CONT TestParsePathInfoJSON/whitespace_only307=== CONT TestParsePathInfoJSON/invalid_JSON308=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512309=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)310=== RUN TestPartSizeForNAR/1_TiB311=== PAUSE TestPartSizeForNAR/1_TiB312=== RUN TestPartSizeForNAR/5_TiB_S3_max_object313=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object314=== RUN TestPartSizeForNAR/capped_at_5_GiB315=== PAUSE TestPartSizeForNAR/capped_at_5_GiB316=== CONT TestPartSizeForNAR/zero_stays_at_minimum317=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512318=== CONT TestPartSizeForNAR/5_TiB_S3_max_object319=== CONT TestPartSizeForNAR/1_TiB320=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped321=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3222026/10/01 09:42:10 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=2000323=== CONT TestEncodeNixBase32/empty_input324--- PASS: TestEncodeNixBase32 (0.04s)325 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)326 --- PASS: TestEncodeNixBase32/empty_input (0.00s)327=== CONT TestPartSizeForNAR/capped_at_5_GiB328=== CONT TestFilterOversizedClosures/all_closures_skipped3292026/10/01 09:42:10 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=50330--- PASS: TestFilterOversizedClosures (0.04s)331 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)332 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)333 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)334=== RUN TestConvertHashToNix32/invalid_format335=== PAUSE TestConvertHashToNix32/invalid_format336=== CONT TestConvertHashToNix32/SRI_format_to_Nix32337=== CONT TestParsePathInfoJSON/Lix_format338--- PASS: TestParsePathInfoJSON (0.04s)339 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)341 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)342 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)343 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)344=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts345=== CONT TestPartSizeForNAR/small_stays_at_minimum346=== CONT TestConvertHashToNix32/invalid_format347=== CONT TestConvertHashToNix32/already_Nix32_format348--- PASS: TestConvertHashToNix32 (0.04s)349 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)350 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)351 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)352=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum353--- PASS: TestPartSizeForNAR (0.03s)354 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)356 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)357 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)358 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)359 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)361=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI362--- PASS: TestPathInfoHashCompatibility (0.05s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)364 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)365 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)366 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)367=== CONT TestSetClientTLSErrors/invalid_ca_file368--- PASS: TestPathInfoCACompatibility (0.04s)369 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)370 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)371 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)372 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)373 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.01s)374--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)375 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)376 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)377--- PASS: TestSetClientTLSErrors (0.05s)378 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.01s)3822026/10/01 09:42:10 http: TLS handshake error from 127.0.0.1:59464: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.04s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathWriterError (0.06s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)389--- PASS: TestStreamPushRequestLine (0.06s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres2967901290/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/postgres2967901290/data -l logfile start422423/build/postgres2967901290:5432 - no response4242026-10-01 09:42:12.571 UTC [126] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 09:42:12.572 UTC [126] LOG: listening on Unix socket "/build/postgres2967901290/.s.PGSQL.5432"4262026-10-01 09:42:12.576 UTC [133] LOG: database system was shut down at 2026-10-01 09:42:12 UTC4272026-10-01 09:42:12.580 UTC [126] LOG: database system is ready to accept connections428/build/postgres2967901290:5432 - accepting connections429{"timestamp":"2026-10-01T09:42:12.77176429Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"410899a9-f386-4b29-b64d-49ac9b7fcef0","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 09:42:12.957 UTC [368] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 09:42:12.957 UTC [368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 09:42:12 OK 20241026095416_initial_model.sql (11.06ms)4762026/10/01 09:42:12 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)4772026/10/01 09:42:12 OK 20251218171726_add_pins.sql (3.13ms)4782026/10/01 09:42:12 OK 20260628120000_add_object_size_and_stats.sql (2.1ms)4792026/10/01 09:42:12 OK 20260905000000_add_claims.sql (2.35ms)4802026/10/01 09:42:12 OK 20260920000000_drop_claims.sql (1.36ms)4812026/10/01 09:42:12 OK 20260923120000_add_pushes.sql (1.12ms)4822026/10/01 09:42:12 goose: successfully migrated database to version: 202609231200004832026/10/01 09:42:12 OK 1_commit_pending_closure.sql (1.71ms)4842026/10/01 09:42:12 OK 2_object_stats_trigger.sql (685.43µs)4852026/10/01 09:42:12 OK 3_commit_push.sql (575.61µs)4862026/10/01 09:42:12 goose: up to current file version: 34872026/10/01 09:42:13 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 09:42:13 INFO lead: released remote=192.0.2.1:12344892026/10/01 09:42:13 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 09:42:13 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 09:42:13.722 UTC [379] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 09:42:13.722 UTC [379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 09:42:13 OK 20241026095416_initial_model.sql (9.02ms)4982026/10/01 09:42:13 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)4992026/10/01 09:42:13 OK 20251218171726_add_pins.sql (2.76ms)5002026/10/01 09:42:13 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)5012026/10/01 09:42:13 OK 20260905000000_add_claims.sql (2.6ms)5022026/10/01 09:42:13 OK 20260920000000_drop_claims.sql (1.63ms)5032026/10/01 09:42:13 OK 20260923120000_add_pushes.sql (1.37ms)5042026/10/01 09:42:13 goose: successfully migrated database to version: 202609231200005052026/10/01 09:42:13 OK 1_commit_pending_closure.sql (1.7ms)5062026/10/01 09:42:13 OK 2_object_stats_trigger.sql (678.13µs)5072026/10/01 09:42:13 OK 3_commit_push.sql (583.69µs)5082026/10/01 09:42:13 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCEndsOnShutdown543=== PAUSE TestGCEndsOnShutdown544=== RUN TestGCTaskStore_StartNew545=== PAUSE TestGCTaskStore_StartNew546=== RUN TestGCTaskStore_DeduplicateSameParams547=== PAUSE TestGCTaskStore_DeduplicateSameParams548=== RUN TestGCTaskStore_ConflictDifferentParams549=== PAUSE TestGCTaskStore_ConflictDifferentParams550=== RUN TestGCTaskStore_GetEmpty551=== PAUSE TestGCTaskStore_GetEmpty552=== RUN TestGCTaskStore_GetReturnsLatest553=== PAUSE TestGCTaskStore_GetReturnsLatest554=== RUN TestGCTaskStore_CompletedAllowsNewTask555=== PAUSE TestGCTaskStore_CompletedAllowsNewTask556=== RUN TestGCTaskStore_PhaseUpdates557=== PAUSE TestGCTaskStore_PhaseUpdates558=== RUN TestGCTaskStore_Fail559=== PAUSE TestGCTaskStore_Fail560=== RUN TestGracefulShutdownDrainsInflight561=== PAUSE TestGracefulShutdownDrainsInflight562=== RUN TestService_healthCheckHandler563=== PAUSE TestService_healthCheckHandler564=== RUN TestService_readinessHandler565=== PAUSE TestService_readinessHandler566=== RUN TestGenerateLandingPage567=== PAUSE TestGenerateLandingPage568=== RUN TestCacheConfigHandlerMaxNarSize569=== PAUSE TestCacheConfigHandlerMaxNarSize570=== RUN TestCreatePendingClosureRejectsOversizedNAR571=== PAUSE TestCreatePendingClosureRejectsOversizedNAR572=== RUN TestNARDeduplicationMetadataUploadBug573=== PAUSE TestNARDeduplicationMetadataUploadBug574=== RUN TestMetricsInventory575=== PAUSE TestMetricsInventory576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestOrphanedObjectsGC589=== PAUSE TestOrphanedObjectsGC590=== RUN TestOrphanedObjectsGCStressTest591=== PAUSE TestOrphanedObjectsGCStressTest592=== RUN TestCreatePin_ReservedPins593=== PAUSE TestCreatePin_ReservedPins594=== RUN TestPresentReportsOnlyClosureRoots595=== PAUSE TestPresentReportsOnlyClosureRoots596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 09:42:13 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 09:42:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestIsValidUploadKey675=== PAUSE TestIsValidUploadKey676=== RUN TestUploadHandlersRejectInvalidKeys677=== PAUSE TestUploadHandlersRejectInvalidKeys678=== RUN TestUploadHandlersRejectOversizedBody679=== PAUSE TestUploadHandlersRejectOversizedBody680=== RUN TestService_cleanupPendingClosuresHandler681=== PAUSE TestService_cleanupPendingClosuresHandler682=== RUN TestService_createPendingClosureHandler683=== PAUSE TestService_createPendingClosureHandler684=== RUN TestService_verifyS3Integrity685=== PAUSE TestService_verifyS3Integrity686=== RUN TestCompleteMultipartUnregistered687=== PAUSE TestCompleteMultipartUnregistered688=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT689=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT690=== CONT TestProxyWriteTimeout691=== CONT TestGracefulShutdownDrainsInflight692=== CONT TestPresignedUploadRegisteredBeforeCommit693=== CONT TestPush_RejectsBadRequests694=== CONT TestPushDedupSurvivesConcurrentGC695=== CONT TestReadProxyNarinfo6962026/10/01 09:42:14 INFO Starting HTTP server address=127.0.0.1:45193697=== CONT TestService_healthCheckHandler698=== RUN TestProxyWriteTimeout/narinfo699=== CONT TestPushWaitsForSweepHoldingRow700=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle701=== CONT TestSkippedUploadsHandler702=== CONT TestParseSize7032026/10/01 09:42:14 INFO Shutdown signal received, draining in-flight requests timeout=10s704=== CONT TestService_Rustfstest705=== CONT TestCompletedNarNotReofferedAcrossClosures706=== CONT TestCompleteMultipartUpload_ErrorButObjectExists707=== CONT TestRedundantMultipartUpload7082026/10/01 09:42:14 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000709=== CONT TestPush_SignsNarinfosOfItsPendingObjects710=== CONT TestService_AuthMiddleware711=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT712=== CONT TestCompleteMultipartUnregistered713=== CONT TestService_verifyS3Integrity714=== CONT TestService_createPendingClosureHandler715=== CONT TestService_cleanupPendingClosuresHandler716=== CONT TestUploadHandlersRejectOversizedBody717=== CONT TestUploadHandlersRejectInvalidKeys718=== PAUSE TestProxyWriteTimeout/narinfo719--- PASS: TestParseSize (0.00s)720=== CONT TestIsValidUploadKey721=== RUN TestIsValidUploadKey/narinfo722=== PAUSE TestIsValidUploadKey/narinfo723=== RUN TestIsValidUploadKey/nar_zst724=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info725=== RUN TestProxyWriteTimeout/1_GiB_nar726=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info727=== PAUSE TestIsValidUploadKey/nar_zst728=== PAUSE TestProxyWriteTimeout/1_GiB_nar729=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal730=== RUN TestIsValidUploadKey/nar_xz731=== RUN TestProxyWriteTimeout/10_GiB_nar732=== PAUSE TestIsValidUploadKey/nar_xz733=== PAUSE TestProxyWriteTimeout/10_GiB_nar734=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal735=== RUN TestIsValidUploadKey/nar_plain736=== RUN TestProxyWriteTimeout/unknown_size737=== PAUSE TestProxyWriteTimeout/unknown_size738=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key739=== CONT TestForceGCDuringPushOffersSweptObject740=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows741=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows742=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key743=== PAUSE TestIsValidUploadKey/nar_plain744=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key745=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check746=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check747=== CONT TestSweepRechecksPendingAfterLocking748=== RUN TestIsValidUploadKey/listing749=== PAUSE TestIsValidUploadKey/listing750=== RUN TestIsValidUploadKey/build_log751=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key752=== PAUSE TestIsValidUploadKey/build_log753=== CONT TestGetExistingObjectsLocksRows754=== RUN TestIsValidUploadKey/build_log_home-manager_file755=== PAUSE TestIsValidUploadKey/build_log_home-manager_file756=== RUN TestIsValidUploadKey/build_log_plus_in_name757=== PAUSE TestIsValidUploadKey/build_log_plus_in_name758=== RUN TestIsValidUploadKey/build_log_question_mark759--- PASS: TestSkippedUploadsHandler (0.01s)760=== CONT TestRegisterCompletedObjectNeedsPendingRow761=== PAUSE TestIsValidUploadKey/build_log_question_mark762=== RUN TestIsValidUploadKey/build_log_equals763=== PAUSE TestIsValidUploadKey/build_log_equals764=== RUN TestIsValidUploadKey/realisation765=== PAUSE TestIsValidUploadKey/realisation766=== RUN TestIsValidUploadKey/realisation_plus_in_output767=== PAUSE TestIsValidUploadKey/realisation_plus_in_output768=== RUN TestIsValidUploadKey/nix-cache-info769=== PAUSE TestIsValidUploadKey/nix-cache-info770=== RUN TestIsValidUploadKey/index.html771=== PAUSE TestIsValidUploadKey/index.html772=== RUN TestIsValidUploadKey/narinfo_key,_nar_type773=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type774=== RUN TestIsValidUploadKey/nar_key,_narinfo_type775=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type776=== RUN TestIsValidUploadKey/listing_key,_narinfo_type777=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type778=== RUN TestIsValidUploadKey/traversal779=== PAUSE TestIsValidUploadKey/traversal780=== RUN TestIsValidUploadKey/traversal_nar781=== PAUSE TestIsValidUploadKey/traversal_nar782=== RUN TestIsValidUploadKey/absolute783=== PAUSE TestIsValidUploadKey/absolute784=== RUN TestIsValidUploadKey/empty_key785=== PAUSE TestIsValidUploadKey/empty_key786=== RUN TestIsValidUploadKey/unknown_type787=== PAUSE TestIsValidUploadKey/unknown_type788=== CONT TestSweepSkipsRowsLockedByPush789--- PASS: TestGracefulShutdownDrainsInflight (0.07s)790=== CONT TestFailedS3DeleteKeepsTombstone7912026-10-01 09:42:14.114 UTC [447] ERROR: relation "goose_db_version" does not exist at character 367922026-10-01 09:42:14.114 UTC [447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC793=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts794=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts795=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure796=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure797=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart798=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart799=== CONT TestClientMultipleUploads8002026-10-01 09:42:14.195 UTC [450] ERROR: relation "goose_db_version" does not exist at character 368012026-10-01 09:42:14.195 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026-10-01 09:42:14.213 UTC [451] ERROR: relation "goose_db_version" does not exist at character 368032026-10-01 09:42:14.213 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8042026/10/01 09:42:14 OK 20241026095416_initial_model.sql (57.15ms)8052026-10-01 09:42:14.252 UTC [452] ERROR: relation "goose_db_version" does not exist at character 368062026-10-01 09:42:14.252 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026-10-01 09:42:14.253 UTC [455] ERROR: relation "goose_db_version" does not exist at character 368082026-10-01 09:42:14.253 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8092026-10-01 09:42:14.253 UTC [453] ERROR: relation "goose_db_version" does not exist at character 368102026-10-01 09:42:14.253 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026-10-01 09:42:14.254 UTC [456] ERROR: relation "goose_db_version" does not exist at character 368122026-10-01 09:42:14.254 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026-10-01 09:42:14.255 UTC [454] ERROR: relation "goose_db_version" does not exist at character 368142026-10-01 09:42:14.255 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (6.73ms)8162026/10/01 09:42:14 OK 20251218171726_add_pins.sql (12.84ms)8172026-10-01 09:42:14.273 UTC [457] ERROR: relation "goose_db_version" does not exist at character 368182026-10-01 09:42:14.273 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026/10/01 09:42:14 OK 20241026095416_initial_model.sql (30.63ms)8202026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (7.37ms)8212026-10-01 09:42:14.281 UTC [458] ERROR: relation "goose_db_version" does not exist at character 368222026-10-01 09:42:14.281 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)8242026/10/01 09:42:14 OK 20241026095416_initial_model.sql (26.6ms)8252026/10/01 09:42:14 OK 20260905000000_add_claims.sql (6.38ms)8262026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.92ms)8272026/10/01 09:42:14 OK 20251218171726_add_pins.sql (13.23ms)8282026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (9.42ms)8292026/10/01 09:42:14 OK 20241026095416_initial_model.sql (32.81ms)8302026/10/01 09:42:14 OK 20241026095416_initial_model.sql (26.03ms)8312026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (7.75ms)8322026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200008332026/10/01 09:42:14 OK 20241026095416_initial_model.sql (24.13ms)8342026/10/01 09:42:14 OK 20241026095416_initial_model.sql (26.31ms)8352026/10/01 09:42:14 OK 20241026095416_initial_model.sql (24.46ms)8362026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)8372026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)8382026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)8392026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)8402026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)8412026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3.78ms)8422026/10/01 09:42:14 OK 20251218171726_add_pins.sql (6.43ms)8432026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (7.88ms)8442026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.31ms)8452026/10/01 09:42:14 OK 3_commit_push.sql (1.31ms)8462026/10/01 09:42:14 goose: up to current file version: 38472026/10/01 09:42:14 OK 20251218171726_add_pins.sql (5.55ms)8482026/10/01 09:42:14 OK 20251218171726_add_pins.sql (5.52ms)8492026/10/01 09:42:14 OK 20251218171726_add_pins.sql (6.33ms)8502026/10/01 09:42:14 OK 20241026095416_initial_model.sql (19.59ms)8512026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.52ms)8522026/10/01 09:42:14 OK 20251218171726_add_pins.sql (6.53ms)8532026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.99ms)8542026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.73ms)8552026/10/01 09:42:14 OK 20241026095416_initial_model.sql (13.09ms)8562026-10-01 09:42:14.309 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368572026-10-01 09:42:14.309 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026-10-01 09:42:14.309 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368592026-10-01 09:42:14.309 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026-10-01 09:42:14.310 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368612026-10-01 09:42:14.310 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8622026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)8632026-10-01 09:42:14.311 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368642026-10-01 09:42:14.311 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026-10-01 09:42:14.311 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368662026-10-01 09:42:14.311 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8672026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)8682026-10-01 09:42:14.311 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368692026-10-01 09:42:14.311 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8702026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (6.24ms)8712026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)8722026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (4.24ms)8732026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.63ms)8742026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.84ms)8752026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.66ms)8762026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.75ms)8772026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.76ms)8782026-10-01 09:42:14.315 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368792026-10-01 09:42:14.315 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8802026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.49ms)8812026/10/01 09:42:14 OK 20251218171726_add_pins.sql (5.75ms)8822026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.68ms)8832026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (4.66ms)8842026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200008852026-10-01 09:42:14.317 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368862026-10-01 09:42:14.317 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8872026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.37ms)8882026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.75ms)8892026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.98ms)8902026-10-01 09:42:14.318 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368912026-10-01 09:42:14.318 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8922026-10-01 09:42:14.318 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368932026-10-01 09:42:14.318 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8942026-10-01 09:42:14.318 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368952026-10-01 09:42:14.318 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026/10/01 09:42:14 OK 20260905000000_add_claims.sql (6.08ms)8972026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.22ms)8982026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.32ms)8992026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009002026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.9ms)9012026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.99ms)9022026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.67ms)9032026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.92ms)9042026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.98ms)9052026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.36ms)9062026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009072026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)9082026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.1ms)9092026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)9102026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.54ms)9112026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009122026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3.22ms)9132026-10-01 09:42:14.323 UTC [472] ERROR: relation "goose_db_version" does not exist at character 369142026-10-01 09:42:14.323 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/10/01 09:42:14 OK 3_commit_push.sql (1.46ms)9162026/10/01 09:42:14 goose: up to current file version: 39172026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.58ms)9182026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009192026-10-01 09:42:14.325 UTC [473] ERROR: relation "goose_db_version" does not exist at character 369202026-10-01 09:42:14.325 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.8ms)9222026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (4.25ms)9232026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009242026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3.63ms)9252026/10/01 09:42:14 OK 1_commit_pending_closure.sql (4.28ms)9262026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (4.26ms)9272026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009282026/10/01 09:42:14 OK 20260905000000_add_claims.sql (5.09ms)9292026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3ms)9302026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.66ms)9312026/10/01 09:42:14 OK 3_commit_push.sql (1.56ms)9322026/10/01 09:42:14 goose: up to current file version: 39332026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.67ms)9342026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.21ms)9352026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3ms)9362026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/01 09:42:14 OK 3_commit_push.sql (1.29ms)9382026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.89ms)9392026/10/01 09:42:14 goose: up to current file version: 39402026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.09ms)9412026/10/01 09:42:14 OK 3_commit_push.sql (1.45ms)9422026/10/01 09:42:14 goose: up to current file version: 39432026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2ms)9442026/10/01 09:42:14 OK 3_commit_push.sql (1.22ms)9452026/10/01 09:42:14 goose: up to current file version: 39462026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.52ms)9472026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.71ms)9482026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.99ms)9492026/10/01 09:42:14 OK 3_commit_push.sql (1.43ms)9502026/10/01 09:42:14 goose: up to current file version: 39512026/10/01 09:42:14 OK 20241026095416_initial_model.sql (14.01ms)9522026/10/01 09:42:14 OK 3_commit_push.sql (1.61ms)9532026/10/01 09:42:14 goose: up to current file version: 39542026/10/01 09:42:14 OK 20241026095416_initial_model.sql (14.92ms)9552026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.69ms)9562026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009572026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.72ms)9582026/10/01 09:42:14 goose: successfully migrated database to version: 202609231200009592026/10/01 09:42:14 OK 20241026095416_initial_model.sql (15.3ms)9602026/10/01 09:42:14 OK 20241026095416_initial_model.sql (16.03ms)9612026/10/01 09:42:14 OK 20241026095416_initial_model.sql (17ms)9622026/10/01 09:42:14 OK 20241026095416_initial_model.sql (16.46ms)9632026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.91ms)9642026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (4.12ms)9652026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.39ms)9662026/10/01 09:42:14 OK 20241026095416_initial_model.sql (12.68ms)9672026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (4.2ms)9682026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)9692026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3.39ms)9702026/10/01 09:42:14 OK 20241026095416_initial_model.sql (14.4ms)9712026-10-01 09:42:14.338 UTC [474] ERROR: relation "goose_db_version" does not exist at character 369722026-10-01 09:42:14.338 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9732026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)9742026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)9752026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)9762026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.31ms)9772026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)9782026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.15ms)9792026/10/01 09:42:14 OK 20241026095416_initial_model.sql (13.32ms)9802026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)9812026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)9822026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.12ms)9832026/10/01 09:42:14 OK 3_commit_push.sql (1.58ms)9842026/10/01 09:42:14 goose: up to current file version: 39852026/10/01 09:42:14 OK 3_commit_push.sql (1.43ms)9862026/10/01 09:42:14 goose: up to current file version: 39872026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.17ms)9882026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.18ms)9892026/10/01 09:42:14 OK 20241026095416_initial_model.sql (14.71ms)9902026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.08ms)9912026/10/01 09:42:14 OK 20251218171726_add_pins.sql (5.05ms)9922026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.67ms)9932026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.1ms)9942026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.32ms)9952026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)9962026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)9972026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)9982026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.9ms)9992026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.87ms)10002026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)10012026/10/01 09:42:14 OK 20241026095416_initial_model.sql (12.46ms)10022026/10/01 09:42:14 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10032026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures10042026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)10052026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)10062026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)10072026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)10082026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)10092026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)10102026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4ms)10112026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)1012=== RUN TestPush_RejectsBadRequests/no_roots1013=== PAUSE TestPush_RejectsBadRequests/no_roots1014=== RUN TestPush_RejectsBadRequests/no_objects1015=== PAUSE TestPush_RejectsBadRequests/no_objects1016=== RUN TestPush_RejectsBadRequests/bad_root1017=== PAUSE TestPush_RejectsBadRequests/bad_root1018=== RUN TestPush_RejectsBadRequests/root_not_in_objects1019=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1020=== CONT TestGCMetrics10212026/10/01 09:42:14 OK 20251218171726_add_pins.sql (5.7ms)10222026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)10232026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.48ms)10242026/10/01 09:42:14 OK 20251218171726_add_pins.sql (5.48ms)10252026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)10262026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.61ms)1027--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.35s)1028=== CONT TestGCBugBareHashReferences10292026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.3ms)10302026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.9ms)10312026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.49ms)10322026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.1ms)10332026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.38ms)10342026/10/01 09:42:14 OK 20260905000000_add_claims.sql (5.04ms)10352026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.84ms)10362026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.01ms)10372026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.61ms)10382026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.49ms)10392026/10/01 09:42:14 OK 20260905000000_add_claims.sql (5.07ms)10402026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.64ms)10412026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.78ms)10422026/10/01 09:42:14 OK 20241026095416_initial_model.sql (9.93ms)10432026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)10442026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)10452026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.59ms)10462026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (1.91ms)10472026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.1ms)10482026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.19ms)10492026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010502026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.95ms)10512026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010522026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)10532026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.46ms)10542026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010552026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010562026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.96ms)10572026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.18ms)10582026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)10592026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.84ms)10602026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010612026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.57ms)10622026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.94ms)10632026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.13ms)10642026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010652026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.15ms)10662026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.02ms)10672026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010682026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.15ms)10692026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.11ms)10702026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010712026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.3ms)10722026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.19ms)10732026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.64ms)10742026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.41ms)10752026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.97ms)10762026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.41ms)10772026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.56ms)10782026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.68ms)10792026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000010802026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.11ms)10812026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.2ms)10822026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.42ms)10832026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.12ms)10842026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.4ms)10852026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.66ms)10862026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.93ms)10872026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.99ms)10882026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.9ms)10892026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.01ms)10902026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.59ms)10912026/10/01 09:42:14 OK 3_commit_push.sql (846.99µs)10922026/10/01 09:42:14 goose: up to current file version: 310932026/10/01 09:42:14 OK 3_commit_push.sql (905.87µs)10942026/10/01 09:42:14 goose: up to current file version: 310952026/10/01 09:42:14 OK 3_commit_push.sql (825.99µs)10962026/10/01 09:42:14 goose: up to current file version: 310972026/10/01 09:42:14 OK 3_commit_push.sql (781.49µs)10982026/10/01 09:42:14 goose: up to current file version: 310992026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.77ms)11002026/10/01 09:42:14 OK 3_commit_push.sql (1.62ms)11012026/10/01 09:42:14 goose: up to current file version: 311022026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.76ms)11032026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011042026/10/01 09:42:14 OK 3_commit_push.sql (1.73ms)11052026/10/01 09:42:14 goose: up to current file version: 311062026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.67ms)11072026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.76ms)11082026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.83ms)11092026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.13ms)11102026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011112026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.42ms)11122026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)11132026/10/01 09:42:14 OK 3_commit_push.sql (1.34ms)11142026/10/01 09:42:14 goose: up to current file version: 311152026/10/01 09:42:14 OK 3_commit_push.sql (1.37ms)11162026/10/01 09:42:14 goose: up to current file version: 311172026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.45ms)11182026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.47ms)11192026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011202026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.54ms)11212026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.64ms)11222026/10/01 09:42:14 OK 3_commit_push.sql (628.87µs)11232026/10/01 09:42:14 goose: up to current file version: 311242026/10/01 09:42:14 OK 2_object_stats_trigger.sql (787.17µs)11252026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.67ms)11262026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011272026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11282026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.05ms)11292026/10/01 09:42:14 OK 3_commit_push.sql (759.87µs)11302026/10/01 09:42:14 goose: up to current file version: 311312026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.88ms)11322026/10/01 09:42:14 OK 3_commit_push.sql (711.97µs)11332026/10/01 09:42:14 goose: up to current file version: 311342026/10/01 09:42:14 OK 20260905000000_add_claims.sql (2.84ms)11352026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.69ms)11362026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.66ms)11372026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.61ms)11382026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.84ms)11392026/10/01 09:42:14 OK 3_commit_push.sql (1.79ms)11402026/10/01 09:42:14 goose: up to current file version: 311412026/10/01 09:42:14 OK 3_commit_push.sql (1.69ms)11422026/10/01 09:42:14 goose: up to current file version: 311432026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.32ms)11442026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011452026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.99ms)11462026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.38ms)11472026/10/01 09:42:14 OK 3_commit_push.sql (1.24ms)11482026/10/01 09:42:14 goose: up to current file version: 311492026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11502026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11512026-10-01 09:42:14.423 UTC [481] ERROR: relation "goose_db_version" does not exist at character 3611522026-10-01 09:42:14.423 UTC [481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11532026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11542026-10-01 09:42:14.430 UTC [482] ERROR: relation "goose_db_version" does not exist at character 3611552026-10-01 09:42:14.430 UTC [482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11562026/10/01 09:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11572026/10/01 09:42:14 OK 20241026095416_initial_model.sql (7.73ms)11582026/10/01 09:42:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLmJkNzA4MTljLTAxN2ItNDA5OS1iMGM4LWIwM2Q4ODU1NzlmYngxNzkwODQ3NzM0NDE0NDI4MzY311592026/10/01 09:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11602026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)11612026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.21ms)11622026/10/01 09:42:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLmJkNzA4MTljLTAxN2ItNDA5OS1iMGM4LWIwM2Q4ODU1NzlmYngxNzkwODQ3NzM0NDE0NDI4MzY3 parts=11163--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.44s)1164=== CONT TestLeadEndsOnShutdown11652026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)11662026/10/01 09:42:14 OK 20241026095416_initial_model.sql (9.88ms)11672026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)11682026/10/01 09:42:14 OK 20260905000000_add_claims.sql (2.52ms)11692026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.04ms)11702026/10/01 09:42:14 OK 20251218171726_add_pins.sql (2.82ms)1171--- PASS: TestReadProxyNarinfo (0.45s)1172=== CONT TestLeadElectsOneAndHandsOver11732026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.56ms)11742026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011752026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.58ms)11762026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (2.89ms)11772026/10/01 09:42:14 OK 2_object_stats_trigger.sql (823.49µs)11782026/10/01 09:42:14 OK 3_commit_push.sql (595.41µs)11792026/10/01 09:42:14 goose: up to current file version: 311802026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.45ms)11822026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.1ms)11832026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.05ms)11842026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000011852026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.22ms)11862026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.65ms)11872026/10/01 09:42:14 OK 3_commit_push.sql (1.57ms)11882026/10/01 09:42:14 goose: up to current file version: 311892026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11902026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=011912026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/01 09:42:14 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=011932026/10/01 09:42:14 INFO Vacuumed table table=pending_closures11942026/10/01 09:42:14 INFO Vacuumed table table=pending_objects11952026/10/01 09:42:14 INFO Vacuumed table table=multipart_uploads11962026/10/01 09:42:14 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1197--- PASS: TestService_AuthMiddleware (0.49s)1198=== CONT TestResolveDBConnectionString1199=== RUN TestResolveDBConnectionString/flag_wins1200=== PAUSE TestResolveDBConnectionString/flag_wins1201=== RUN TestResolveDBConnectionString/file_when_flag_empty1202=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1203=== RUN TestResolveDBConnectionString/missing_file_is_an_error1204=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1205=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1206=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1207=== RUN TestResolveDBConnectionString/nothing_configured1208=== PAUSE TestResolveDBConnectionString/nothing_configured1209=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12102026/10/01 09:42:14 INFO Vacuumed table table=closures12112026/10/01 09:42:14 INFO Vacuumed table table=objects12122026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=012132026/10/01 09:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period12142026/10/01 09:42:14 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=012152026/10/01 09:42:14 INFO Vacuumed table table=pending_closures12162026/10/01 09:42:14 INFO Vacuumed table table=pending_objects12172026/10/01 09:42:14 INFO Vacuumed table table=multipart_uploads12182026/10/01 09:42:14 INFO Vacuumed table table=closures12192026/10/01 09:42:14 INFO Vacuumed table table=objects1220--- PASS: TestPushDedupSurvivesConcurrentGC (0.51s)1221=== CONT TestClientFallsBackToClosures12222026-10-01 09:42:14.519 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3612232026-10-01 09:42:14.519 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12242026-10-01 09:42:14.521 UTC [493] ERROR: relation "goose_db_version" does not exist at character 3612252026-10-01 09:42:14.521 UTC [493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12262026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=012272026/10/01 09:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period12282026/10/01 09:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12292026/10/01 09:42:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1230--- PASS: TestCompleteMultipartUnregistered (0.53s)1231=== CONT TestClientPushesUseOnePush12322026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.69ms)12332026/10/01 09:42:14 OK 20241026095416_initial_model.sql (18.21ms)12342026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (8.77ms)12352026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)12362026/10/01 09:42:14 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=012372026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.26ms)12382026/10/01 09:42:14 OK 20251218171726_add_pins.sql (4.69ms)12392026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures12402026/10/01 09:42:14 INFO Vacuumed table table=pending_closures12412026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4ms)12422026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)12432026/10/01 09:42:14 INFO Vacuumed table table=pending_objects12442026/10/01 09:42:14 INFO Vacuumed table table=multipart_uploads12452026/10/01 09:42:14 INFO Vacuumed table table=closures12462026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.33ms)12472026/10/01 09:42:14 INFO Vacuumed table table=objects12482026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.13ms)1249--- PASS: TestSweepRechecksPendingAfterLocking (0.55s)1250=== CONT TestPinProtectsFromGC12512026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.58ms)12522026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.63ms)1253--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.56s)1254=== CONT TestClientSharedPathCommittedMidPush12552026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.21ms)12562026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000012572026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.88ms)12582026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000012592026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.41ms)12602026/10/01 09:42:14 OK 1_commit_pending_closure.sql (3.07ms)12612026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.66ms)12622026-10-01 09:42:14.568 UTC [500] ERROR: relation "goose_db_version" does not exist at character 3612632026-10-01 09:42:14.568 UTC [500] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12642026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.79ms)12652026/10/01 09:42:14 OK 3_commit_push.sql (1.58ms)12662026/10/01 09:42:14 goose: up to current file version: 312672026/10/01 09:42:14 OK 3_commit_push.sql (1.37ms)12682026/10/01 09:42:14 goose: up to current file version: 312692026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures12702026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.39ms)12712026-10-01 09:42:14.587 UTC [504] ERROR: relation "goose_db_version" does not exist at character 3612722026-10-01 09:42:14.587 UTC [504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12732026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)12742026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.59ms)12752026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)12762026/10/01 09:42:14 INFO Received cleanup request method=DELETE path=/api/pending_closures12772026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=012782026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.61ms)12792026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures12802026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.57ms)12812026/10/01 09:42:14 OK 20241026095416_initial_model.sql (10.97ms)12822026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.52ms)12832026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000012842026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)12852026-10-01 09:42:14.611 UTC [505] ERROR: relation "goose_db_version" does not exist at character 3612862026-10-01 09:42:14.611 UTC [505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12872026/10/01 09:42:14 OK 1_commit_pending_closure.sql (8.49ms)12882026/10/01 09:42:14 OK 20251218171726_add_pins.sql (9.22ms)12892026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.23ms)12902026/10/01 09:42:14 INFO Received cleanup request method=DELETE path=/api/pending_closures12912026/10/01 09:42:14 OK 3_commit_push.sql (1.69ms)12922026/10/01 09:42:14 goose: up to current file version: 312932026/10/01 09:42:14 INFO Aborted multipart uploads count=1 kept=012942026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)12952026/10/01 09:42:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12962026-10-01 09:42:14.624 UTC [462] ERROR: Closure does not exist: id=112972026-10-01 09:42:14.624 UTC [462] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12982026-10-01 09:42:14.624 UTC [462] STATEMENT: -- name: CommitPendingClosure :exec1299 SELECT commit_pending_closure($1::bigint)1300 1301--- PASS: TestService_Rustfstest (0.62s)1302=== CONT TestClientWithDependencies1303--- PASS: TestService_cleanupPendingClosuresHandler (0.62s)1304=== CONT TestGCTaskStore_StartNew1305--- PASS: TestGCTaskStore_StartNew (0.00s)1306=== CONT TestGCTaskStore_ConflictDifferentParams1307--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1308=== CONT TestGCTaskStore_DeduplicateSameParams1309--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1310=== CONT TestGCTaskStore_PhaseUpdates1311--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1312=== CONT TestGCTaskStore_Fail1313--- PASS: TestGCTaskStore_Fail (0.00s)1314=== CONT TestGCTaskStore_GetEmpty1315--- PASS: TestGCTaskStore_GetEmpty (0.00s)1316=== CONT TestGCTaskStore_CompletedAllowsNewTask1317--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1318=== CONT TestGCTaskStore_GetReturnsLatest1319--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1320=== CONT TestReadProxyDisabled13212026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.71ms)13222026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.66ms)13232026/10/01 09:42:14 OK 20241026095416_initial_model.sql (10.66ms)13242026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.03ms)13252026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000013262026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)13272026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.95ms)13282026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.24ms)13292026-10-01 09:42:14.633 UTC [512] ERROR: relation "goose_db_version" does not exist at character 3613302026-10-01 09:42:14.633 UTC [512] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13312026/10/01 09:42:14 OK 20251218171726_add_pins.sql (2.92ms)13322026/10/01 09:42:14 OK 3_commit_push.sql (670.63µs)13332026/10/01 09:42:14 goose: up to current file version: 313342026-10-01 09:42:14.636 UTC [515] ERROR: relation "goose_db_version" does not exist at character 3613352026-10-01 09:42:14.636 UTC [515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13362026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4ms)13372026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.5ms)13382026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.77ms)1339--- PASS: TestService_healthCheckHandler (0.64s)1340=== CONT TestReadProxyRangeRequest13412026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.08ms)13422026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000013432026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.53ms)13442026/10/01 09:42:14 OK 20241026095416_initial_model.sql (13.05ms)13452026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.54ms)13462026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.13ms)13472026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)13482026/10/01 09:42:14 OK 3_commit_push.sql (1.28ms)13492026/10/01 09:42:14 goose: up to current file version: 313502026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)13512026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.18ms)13522026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.72ms)13532026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)13542026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)13552026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.52ms)13562026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.26ms)13572026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.84ms)13582026/10/01 09:42:14 INFO Received push request method=POST path=/api/pushes13592026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.52ms)13602026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000013612026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.92ms)13622026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.65ms)13632026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.26ms)13642026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000013652026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.63ms)13662026/10/01 09:42:14 OK 3_commit_push.sql (2.48ms)13672026/10/01 09:42:14 goose: up to current file version: 313682026/10/01 09:42:14 OK 1_commit_pending_closure.sql (4.37ms)13692026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.63ms)13702026/10/01 09:42:14 OK 3_commit_push.sql (1.47ms)13712026/10/01 09:42:14 goose: up to current file version: 313722026/10/01 09:42:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13732026/10/01 09:42:14 INFO Signed narinfos id=1 count=11374--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.68s)1375=== CONT TestReadRedirectKeepsNarinfoProxied13762026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures13772026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures13782026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures13792026-10-01 09:42:14.699 UTC [520] ERROR: relation "goose_db_version" does not exist at character 3613802026-10-01 09:42:14.699 UTC [520] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13812026-10-01 09:42:14.702 UTC [521] ERROR: relation "goose_db_version" does not exist at character 3613822026-10-01 09:42:14.702 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1383--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.70s)1384=== CONT TestReadRedirectUsesPublicS3URL13852026/10/01 09:42:14 OK 20241026095416_initial_model.sql (9.85ms)13862026/10/01 09:42:14 OK 20241026095416_initial_model.sql (9.21ms)13872026-10-01 09:42:14.721 UTC [523] ERROR: relation "goose_db_version" does not exist at character 3613882026-10-01 09:42:14.721 UTC [523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13892026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)13902026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)13912026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.49ms)13922026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.6ms)13932026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)13942026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)13952026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.15ms)13962026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.5ms)13972026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.83ms)13982026/10/01 09:42:14 OK 20241026095416_initial_model.sql (10.4ms)13992026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.14ms)14002026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)14012026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.16ms)14022026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000014032026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.99ms)14042026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000014052026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.39ms)14062026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.45ms)1407--- PASS: TestGetExistingObjectsLocksRows (0.73s)14082026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.17ms)1409=== CONT TestReadRedirectNar14102026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.58ms)14112026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.43ms)14122026/10/01 09:42:14 OK 3_commit_push.sql (1.09ms)14132026/10/01 09:42:14 goose: up to current file version: 314142026/10/01 09:42:14 OK 3_commit_push.sql (965.17µs)14152026/10/01 09:42:14 goose: up to current file version: 314162026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)14172026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.03ms)14182026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (1.94ms)14192026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.53ms)14202026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000014212026-10-01 09:42:14.755 UTC [528] ERROR: relation "goose_db_version" does not exist at character 3614222026-10-01 09:42:14.755 UTC [528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14232026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.18ms)14242026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.72ms)14252026/10/01 09:42:14 OK 3_commit_push.sql (1.15ms)14262026/10/01 09:42:14 goose: up to current file version: 314272026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.81ms)14282026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures14292026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)14302026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=014312026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.37ms)14322026/10/01 09:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period14332026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)14342026/10/01 09:42:14 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=014352026-10-01 09:42:14.783 UTC [531] ERROR: relation "goose_db_version" does not exist at character 3614362026-10-01 09:42:14.783 UTC [531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/10/01 09:42:14 INFO Vacuumed table table=pending_closures14382026/10/01 09:42:14 INFO Vacuumed table table=pending_objects14392026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.02ms)14402026/10/01 09:42:14 INFO Vacuumed table table=multipart_uploads14412026/10/01 09:42:14 INFO Vacuumed table table=closures14422026/10/01 09:42:14 INFO Vacuumed table table=objects14432026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.5ms)14442026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.31ms)14452026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000014462026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=014472026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.47ms)14482026/10/01 09:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period14492026/10/01 09:42:14 OK 2_object_stats_trigger.sql (2.11ms)14502026/10/01 09:42:14 OK 3_commit_push.sql (1.41ms)14512026/10/01 09:42:14 goose: up to current file version: 314522026/10/01 09:42:14 OK 20241026095416_initial_model.sql (9.86ms)14532026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)14542026/10/01 09:42:14 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=014552026/10/01 09:42:14 OK 20251218171726_add_pins.sql (2.82ms)14562026/10/01 09:42:14 INFO Vacuumed table table=pending_closures14572026/10/01 09:42:14 INFO Vacuumed table table=pending_objects14582026/10/01 09:42:14 INFO Vacuumed table table=multipart_uploads14592026/10/01 09:42:14 INFO Vacuumed table table=closures14602026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (2.91ms)14612026/10/01 09:42:14 INFO Vacuumed table table=objects1462--- PASS: TestSweepSkipsRowsLockedByPush (0.74s)1463=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14642026/10/01 09:42:14 OK 20260905000000_add_claims.sql (2.87ms)14652026/10/01 09:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14662026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.02ms)14672026-10-01 09:42:14.813 UTC [533] ERROR: relation "goose_db_version" does not exist at character 3614682026-10-01 09:42:14.813 UTC [533] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14692026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.63ms)14702026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000014712026/10/01 09:42:14 OK 1_commit_pending_closure.sql (1.67ms)14722026/10/01 09:42:14 OK 2_object_stats_trigger.sql (771.75µs)14732026/10/01 09:42:14 OK 3_commit_push.sql (653.69µs)14742026/10/01 09:42:14 goose: up to current file version: 314752026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=014762026/10/01 09:42:14 OK 20241026095416_initial_model.sql (9.67ms)14772026/10/01 09:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period14782026/10/01 09:42:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLjA3YzI1YmQzLTYxMjktNDhhOS1hYzRhLTc5MGFhZjE4MTFlN3gxNzkwODQ3NzM0NDYzNDQ3NjMz parts=1214792026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)14802026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures14812026/10/01 09:42:14 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=014822026/10/01 09:42:14 OK 20251218171726_add_pins.sql (2.59ms)14832026/10/01 09:42:14 INFO Vacuumed table table=pending_closures1484--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.83s)1485=== CONT TestReadProxyInvalidPath14862026/10/01 09:42:14 INFO Vacuumed table table=pending_objects14872026/10/01 09:42:14 INFO Vacuumed table table=multipart_uploads14882026/10/01 09:42:14 INFO Vacuumed table table=closures14892026/10/01 09:42:14 INFO Vacuumed table table=objects14902026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)1491--- PASS: TestGCMetrics (0.49s)1492=== CONT TestPush_CompleteCommitsEveryRoot1493=== NAME TestClientMultipleUploads1494 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads558855992/001/store/kgl3nzvrvbmamfb36qf52xqb54if2vi4-test-file-0.txt14952026/10/01 09:42:14 OK 20260905000000_add_claims.sql (7.94ms)14962026/10/01 09:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14972026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.77ms)14982026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.67ms)14992026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000015002026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.27ms)15012026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.74ms)15022026/10/01 09:42:14 INFO Aborted multipart uploads count=0 kept=015032026/10/01 09:42:14 OK 3_commit_push.sql (1.35ms)15042026/10/01 09:42:14 goose: up to current file version: 315052026/10/01 09:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period15062026/10/01 09:42:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLmFmNjkwYjUyLTQ3ZDItNGVkNS1hYmU4LTFiMjBmYTgxNzNkYXgxNzkwODQ3NzM0NDgzMTM5Mjky parts=1215072026/10/01 09:42:14 INFO lead: acquired remote=192.0.2.1:123415082026/10/01 09:42:14 INFO lead: released remote=192.0.2.1:12341509--- PASS: TestLeadEndsOnShutdown (0.42s)1510=== CONT TestReadProxyRootRedirectsToIndexHTML15112026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures1512=== NAME TestClientMultipleUploads1513 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads558855992/001/store/cfnpfwv382p7rx183bh2w44djsvsmn5b-test-file-1.txt15142026/10/01 09:42:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15152026/10/01 09:42:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15162026/10/01 09:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1517--- PASS: TestFailedS3DeleteKeepsTombstone (0.80s)1518=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15192026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures15202026-10-01 09:42:14.882 UTC [599] ERROR: relation "goose_db_version" does not exist at character 3615212026-10-01 09:42:14.882 UTC [599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15222026/10/01 09:42:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLjA5NGViZWQ4LTRmMTUtNDYyMS04ZjRjLWNhZjY2ZDNhNjI3OHgxNzkwODQ3NzM0NTgyMzA3OTE1 parts=1015232026/10/01 09:42:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15242026/10/01 09:42:14 INFO lead: acquired remote=192.0.2.1:123415252026/10/01 09:42:14 INFO Completed upload id=115262026/10/01 09:42:14 OK 20241026095416_initial_model.sql (14.91ms)15272026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures15282026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)15292026/10/01 09:42:14 INFO Received uploads request method=POST path=/api/pending_closures15302026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.72ms)1531=== NAME TestClientMultipleUploads1532 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads558855992/001/store/70i6q7iig60zj9yvxw15rp4v29df33iz-test-file-2.txt15332026/10/01 09:42:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15342026/10/01 09:42:14 WARN Found objects in DB but missing from S3, will re-upload count=11535--- PASS: TestService_verifyS3Integrity (0.91s)1536=== CONT TestReadProxyConditionalGet15372026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)15382026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.29ms)15392026-10-01 09:42:14.925 UTC [621] ERROR: relation "goose_db_version" does not exist at character 3615402026-10-01 09:42:14.925 UTC [621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15412026-10-01 09:42:14.926 UTC [622] ERROR: relation "goose_db_version" does not exist at character 3615422026-10-01 09:42:14.926 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15432026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (9.51ms)1544--- PASS: TestPushWaitsForSweepHoldingRow (0.93s)1545=== CONT TestReadProxyHead15462026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.86ms)15472026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000015482026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.83ms)15492026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.58ms)15502026/10/01 09:42:14 OK 3_commit_push.sql (1.17ms)15512026/10/01 09:42:14 goose: up to current file version: 315522026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.81ms)15532026/10/01 09:42:14 OK 20241026095416_initial_model.sql (12.1ms)15542026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)15552026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)15562026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.67ms)15572026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.95ms)15582026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4ms)15592026-10-01 09:42:14.956 UTC [643] ERROR: relation "goose_db_version" does not exist at character 3615602026-10-01 09:42:14.956 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15612026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)15622026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.17ms)15632026/10/01 09:42:14 OK 20260905000000_add_claims.sql (4.08ms)15642026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.62ms)15652026-10-01 09:42:14.963 UTC [645] ERROR: relation "goose_db_version" does not exist at character 3615662026-10-01 09:42:14.963 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15672026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3.25ms)15682026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000015692026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (3.56ms)15702026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.35ms)15712026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (3ms)15722026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000015732026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.48ms)15742026/10/01 09:42:14 OK 3_commit_push.sql (1.22ms)15752026/10/01 09:42:14 goose: up to current file version: 315762026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.78ms)15772026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.47ms)15782026/10/01 09:42:14 OK 3_commit_push.sql (1.21ms)15792026/10/01 09:42:14 goose: up to current file version: 315802026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.07ms)15812026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)15822026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.97ms)15832026/10/01 09:42:14 OK 20241026095416_initial_model.sql (11.21ms)15842026/10/01 09:42:14 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)15852026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)15862026/10/01 09:42:14 OK 20251218171726_add_pins.sql (3.78ms)15872026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.5ms)15882026/10/01 09:42:14 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)15892026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.95ms)15902026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (2.04ms)15912026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000015922026/10/01 09:42:14 OK 20260905000000_add_claims.sql (3.53ms)15932026/10/01 09:42:14 OK 1_commit_pending_closure.sql (2.29ms)15942026/10/01 09:42:14 INFO Received push request method=POST path=/api/pushes15952026/10/01 09:42:14 OK 2_object_stats_trigger.sql (1.21ms)15962026/10/01 09:42:14 OK 20260920000000_drop_claims.sql (2.76ms)15972026/10/01 09:42:14 OK 3_commit_push.sql (1.1ms)15982026/10/01 09:42:14 goose: up to current file version: 315992026/10/01 09:42:14 OK 20260923120000_add_pushes.sql (1.89ms)16002026/10/01 09:42:14 goose: successfully migrated database to version: 2026092312000016012026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.13ms)16022026/10/01 09:42:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16032026/10/01 09:42:15 INFO Uploading cfnpfwv382p7rx183bh2w44djsvsmn5b-test-file-1.txt (160B)16042026/10/01 09:42:15 INFO Uploading 70i6q7iig60zj9yvxw15rp4v29df33iz-test-file-2.txt (160B)16052026/10/01 09:42:15 INFO Uploading kgl3nzvrvbmamfb36qf52xqb54if2vi4-test-file-0.txt (160B)16062026/10/01 09:42:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16072026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.45ms)16082026/10/01 09:42:15 OK 3_commit_push.sql (913.21µs)16092026/10/01 09:42:15 goose: up to current file version: 316102026/10/01 09:42:15 WARN Failed to register uploaded object key=70i6q7iig60zj9yvxw15rp4v29df33iz.ls error="server returned 404: 404 page not found\n"16112026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16122026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16132026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16142026/10/01 09:42:15 WARN Failed to register uploaded object key=kgl3nzvrvbmamfb36qf52xqb54if2vi4.ls error="server returned 404: 404 page not found\n"16152026/10/01 09:42:15 WARN Failed to register uploaded object key=cfnpfwv382p7rx183bh2w44djsvsmn5b.ls error="server returned 404: 404 page not found\n"16162026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16172026/10/01 09:42:15 INFO Signed narinfos id=1 count=316182026/10/01 09:42:15 INFO Uploading 3 narinfos16192026-10-01 09:42:15.009 UTC [685] ERROR: relation "goose_db_version" does not exist at character 3616202026-10-01 09:42:15.009 UTC [685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16212026/10/01 09:42:15 WARN Failed to register uploaded object key=70i6q7iig60zj9yvxw15rp4v29df33iz.narinfo error="server returned 404: 404 page not found\n"16222026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete16232026/10/01 09:42:15 WARN Failed to register uploaded object key=cfnpfwv382p7rx183bh2w44djsvsmn5b.narinfo error="server returned 404: 404 page not found\n"16242026/10/01 09:42:15 WARN Failed to register uploaded object key=kgl3nzvrvbmamfb36qf52xqb54if2vi4.narinfo error="server returned 404: 404 page not found\n"16252026-10-01 09:42:15.015 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3616262026-10-01 09:42:15.015 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16272026/10/01 09:42:15 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLmMyY2VkYjM3LWM5MzEtNDQ5ZS1iYzc1LTE2NDAyZGQxZTY1ZXgxNzkwODQ3NzM0Njk2MTU2OTUy parts=1016282026/10/01 09:42:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16292026/10/01 09:42:15 INFO Completed upload id=116302026/10/01 09:42:15 INFO Upload complete. (64ms)1631=== NAME TestClientMultipleUploads1632 client_integration_test.go:369: Uploaded 3 paths in 106.680031ms16332026/10/01 09:42:15 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016342026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures16352026/10/01 09:42:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures16362026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.4ms)16372026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)1638--- PASS: TestClientMultipleUploads (0.87s)16392026/10/01 09:42:15 OK 20241026095416_initial_model.sql (9.3ms)1640=== CONT TestTombstonedObjectOfferedWithoutWaiting16412026/10/01 09:42:15 OK 20251218171726_add_pins.sql (2.65ms)16422026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)16432026/10/01 09:42:15 INFO Aborted multipart uploads count=0 kept=016442026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (2.67ms)16452026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.15ms)16462026/10/01 09:42:15 OK 20260905000000_add_claims.sql (2.43ms)16472026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)16482026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.91ms)16492026/10/01 09:42:15 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=016502026/10/01 09:42:15 INFO lead: released remote=192.0.2.1:123416512026/10/01 09:42:15 OK 20260905000000_add_claims.sql (8.54ms)16522026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (8.51ms)16532026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000016542026/10/01 09:42:15 INFO Vacuumed table table=pending_closures16552026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.85ms)16562026/10/01 09:42:15 INFO Vacuumed table table=pending_objects16572026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.32ms)16582026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.79ms)16592026/10/01 09:42:15 INFO Vacuumed table table=multipart_uploads16602026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.67ms)16612026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000016622026/10/01 09:42:15 OK 3_commit_push.sql (1.67ms)16632026/10/01 09:42:15 goose: up to current file version: 316642026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.57ms)16652026/10/01 09:42:15 INFO Vacuumed table table=closures16662026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.23ms)16672026/10/01 09:42:15 OK 3_commit_push.sql (905.97µs)16682026/10/01 09:42:15 goose: up to current file version: 316692026/10/01 09:42:15 INFO Vacuumed table table=objects1670--- PASS: TestReadProxyDisabled (0.44s)1671=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1672=== NAME TestPinProtectsFromGC1673 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1938861288/001/store/pncq4l80gcdrhgj5f2dg4bx2y1bhydwa-pinned-file.txt1674 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1938861288/001/store/6va4iph845hldmqcs95awgm2fsbv0y4l-unpinned-file.txt1675--- PASS: TestGCBugBareHashReferences (0.72s)1676=== CONT TestGCSweepSkipsPendingObjects16772026/10/01 09:42:15 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001678--- PASS: TestService_createPendingClosureHandler (1.07s)1679=== CONT TestGCSweepDeliversEachKeyOnce16802026/10/01 09:42:15 INFO lead: acquired remote=192.0.2.1:12341681--- PASS: TestReadProxyRangeRequest (0.45s)1682=== CONT TestService_ReadScope_PublicByDefault16832026/10/01 09:42:15 INFO lead: released remote=192.0.2.1:12341684--- PASS: TestLeadElectsOneAndHandsOver (0.65s)1685=== CONT TestDeduplicatedObjectsRecordedAsPending1686--- PASS: TestReadRedirectKeepsNarinfoProxied (0.43s)1687=== CONT TestClientIntegration16882026-10-01 09:42:15.124 UTC [927] ERROR: relation "goose_db_version" does not exist at character 3616892026-10-01 09:42:15.124 UTC [927] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1690=== NAME TestClientWithDependencies1691 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1354658245/001/store/8qvl3gx9y23r18d9mrdkay8gcv82x78m-test-script16922026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures1693--- PASS: TestReadRedirectUsesPublicS3URL (0.43s)1694=== CONT TestReadProxyNarStreaming16952026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes16962026/10/01 09:42:15 OK 20241026095416_initial_model.sql (19.15ms)16972026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures16982026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)16992026/10/01 09:42:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17002026/10/01 09:42:15 INFO Uploading pncq4l80gcdrhgj5f2dg4bx2y1bhydwa-pinned-file.txt (128B)17012026/10/01 09:42:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17022026/10/01 09:42:15 INFO Uploading 3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk-shared-dep (136B)17032026/10/01 09:42:15 INFO Uploading g5lgzbbxgci4vv30q40k7ym3mmhpi98s-b (216B)17042026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.3ms)17052026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17062026/10/01 09:42:15 WARN Failed to register uploaded object key=pncq4l80gcdrhgj5f2dg4bx2y1bhydwa.ls error="server returned 404: 404 page not found\n"17072026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1708--- PASS: TestReadRedirectNar (0.42s)1709=== CONT TestClientErrorHandling1710=== RUN TestClientErrorHandling/InvalidStorePath1711=== PAUSE TestClientErrorHandling/InvalidStorePath17122026/10/01 09:42:15 WARN Failed to register uploaded object key=f0s038qsbqsdrghzhr7z8bkq2xz3i4kj.ls error="server returned 404: 404 page not found\n"1713=== RUN TestClientErrorHandling/InvalidAuthToken1714=== PAUSE TestClientErrorHandling/InvalidAuthToken1715=== RUN TestClientErrorHandling/ServerNotAvailable1716=== PAUSE TestClientErrorHandling/ServerNotAvailable1717=== CONT TestReadProxy40417182026/10/01 09:42:15 WARN Failed to register uploaded object key=3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk.ls error="server returned 404: 404 page not found\n"17192026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17202026/10/01 09:42:15 INFO Signed narinfos id=1 count=117212026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1rvp6kqcfhqiavwfgjvsp6h7r7w2piyw7064g3mn7qkai2bwngir.nar.zst error="server returned 404: 404 page not found\n"17222026/10/01 09:42:15 INFO Uploading 1 narinfos17232026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17242026-10-01 09:42:15.164 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 3617252026-10-01 09:42:15.164 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17262026/10/01 09:42:15 INFO Signed narinfos id=1 count=217272026/10/01 09:42:15 WARN Failed to register uploaded object key=g5lgzbbxgci4vv30q40k7ym3mmhpi98s.ls error="server returned 404: 404 page not found\n"17282026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17292026/10/01 09:42:15 INFO Signed narinfos id=2 count=217302026/10/01 09:42:15 INFO Uploading 4 narinfos17312026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)17322026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes1733=== NAME TestClientWithDependencies1734 client_integration_test.go:615: Found 1 dependencies (including self)17352026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete17362026/10/01 09:42:15 WARN Failed to register uploaded object key=pncq4l80gcdrhgj5f2dg4bx2y1bhydwa.narinfo error="server returned 404: 404 page not found\n"17372026/10/01 09:42:15 WARN Failed to register uploaded object key=f0s038qsbqsdrghzhr7z8bkq2xz3i4kj.narinfo error="server returned 404: 404 page not found\n"17382026/10/01 09:42:15 WARN Failed to register uploaded object key=3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk.narinfo error="server returned 404: 404 page not found\n"17392026/10/01 09:42:15 WARN Failed to register uploaded object key=g5lgzbbxgci4vv30q40k7ym3mmhpi98s.narinfo error="server returned 404: 404 page not found\n"17402026-10-01 09:42:15.170 UTC [1042] ERROR: relation "goose_db_version" does not exist at character 3617412026-10-01 09:42:15.170 UTC [1042] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17422026/10/01 09:42:15 OK 20260905000000_add_claims.sql (5.07ms)17432026/10/01 09:42:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17442026/10/01 09:42:15 WARN Failed to register uploaded object key=3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk.narinfo error="server returned 404: 404 page not found\n"17452026-10-01 09:42:15.171 UTC [1043] ERROR: relation "goose_db_version" does not exist at character 3617462026-10-01 09:42:15.171 UTC [1043] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17472026/10/01 09:42:15 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17482026/10/01 09:42:15 INFO Uploading l7gdb8pa2cprkw6kg99qf60513yixflv-shared-dep (136B)17492026/10/01 09:42:15 INFO Uploading 0ms8ng6hhsyi1z4jb8phg7d71shv0krz-top (224B)17502026/10/01 09:42:15 INFO Upload complete. (62ms)17512026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes17522026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.45ms)17532026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes17542026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17552026/10/01 09:42:15 WARN Failed to register uploaded object key=l7gdb8pa2cprkw6kg99qf60513yixflv.ls error="server returned 404: 404 page not found\n"17562026/10/01 09:42:15 WARN Failed to register uploaded object key=0ms8ng6hhsyi1z4jb8phg7d71shv0krz.ls error="server returned 404: 404 page not found\n"17572026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1d7zy03yyqjfbcny73ix1v2pg18bmxs73snmmhpgw4cjrpx16h3j.nar.zst error="server returned 404: 404 page not found\n"17582026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17592026/10/01 09:42:15 INFO Completed upload id=117602026/10/01 09:42:15 INFO Signed narinfos id=1 count=217612026/10/01 09:42:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17622026/10/01 09:42:15 INFO Uploading 2 narinfos17632026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete17642026/10/01 09:42:15 WARN Failed to register uploaded object key=0ms8ng6hhsyi1z4jb8phg7d71shv0krz.narinfo error="server returned 404: 404 page not found\n"17652026/10/01 09:42:15 WARN Failed to register uploaded object key=l7gdb8pa2cprkw6kg99qf60513yixflv.narinfo error="server returned 404: 404 page not found\n"17662026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (9.96ms)17672026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000017682026/10/01 09:42:15 INFO Completed upload id=217692026/10/01 09:42:15 OK 20241026095416_initial_model.sql (15.48ms)17702026/10/01 09:42:15 INFO Upload complete. (85ms)17712026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.5ms)17722026/10/01 09:42:15 OK 1_commit_pending_closure.sql (3.03ms)1773=== NAME TestClientFallsBackToClosures1774 client_pushes_test.go:112: Retrieved narinfo from S3:1775 StorePath: /build/TestClientFallsBackToClosures3842237889/001/store/3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk-shared-dep17762026/10/01 09:42:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1777 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1778 Compression: zstd1779 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821780 NarSize: 1361781 References: 1782 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17832026/10/01 09:42:15 INFO Uploading qcxqikhcldvnzp4bc5fxjychlg6v0l5z-a (208B)17842026/10/01 09:42:15 INFO Uploading 4i3mifj95mx4c014gi57npgikxsswjsf-shared-dep (136B)17852026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)17862026/10/01 09:42:15 INFO Upload complete. (66ms)17872026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)17882026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.29ms)1789=== NAME TestClientSharedPathCommittedMidPush1790 client_integration_test.go:680: Retrieved narinfo from S3:1791 StorePath: /build/TestClientSharedPathCommittedMidPush1053846507/001/store/l7gdb8pa2cprkw6kg99qf60513yixflv-shared-dep1792 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1793 Compression: zstd1794 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821795 NarSize: 1361796 References: 1797 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17982026/10/01 09:42:15 OK 3_commit_push.sql (1.81ms)1799=== NAME TestClientFallsBackToClosures18002026/10/01 09:42:15 goose: up to current file version: 31801 client_pushes_test.go:112: Retrieved narinfo from S3:1802 StorePath: /build/TestClientFallsBackToClosures3842237889/001/store/f0s038qsbqsdrghzhr7z8bkq2xz3i4kj-a1803 URL: nar/1rvp6kqcfhqiavwfgjvsp6h7r7w2piyw7064g3mn7qkai2bwngir.nar.zst1804 Compression: zstd1805 NarHash: sha256:1rvp6kqcfhqiavwfgjvsp6h7r7w2piyw7064g3mn7qkai2bwngir1806 NarSize: 2161807 References: /build/TestClientFallsBackToClosures3842237889/001/store/3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk-shared-dep1808 CA: text:sha256:0fnhsxc6mhcr3117rpmdqibkz76q5qf5pa4dh6jhpi1c9ql0c09718092026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.08ms)18102026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/0k8dmdrzdap91mzz8vnvwiyajamvq88x72z46kfd7qqgvpa1fkxh.nar.zst error="server returned 404: 404 page not found\n"18112026/10/01 09:42:15 WARN Failed to register uploaded object key=5l4zzah1nwskxq407wvhsv64i1bwjjbj.ls error="server returned 404: 404 page not found\n"18122026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18132026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.18ms)18142026/10/01 09:42:15 WARN Failed to register uploaded object key=qcxqikhcldvnzp4bc5fxjychlg6v0l5z.ls error="server returned 404: 404 page not found\n"18152026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18162026/10/01 09:42:15 WARN Failed to register uploaded object key=4i3mifj95mx4c014gi57npgikxsswjsf.ls error="server returned 404: 404 page not found\n"1817=== NAME TestClientSharedPathCommittedMidPush18182026/10/01 09:42:15 INFO Signed narinfos id=1 count=31819 client_integration_test.go:680: Retrieved narinfo from S3:1820 StorePath: /build/TestClientSharedPathCommittedMidPush1053846507/001/store/0ms8ng6hhsyi1z4jb8phg7d71shv0krz-top1821 URL: nar/1d7zy03yyqjfbcny73ix1v2pg18bmxs73snmmhpgw4cjrpx16h3j.nar.zst1822 Compression: zstd1823 NarHash: sha256:1d7zy03yyqjfbcny73ix1v2pg18bmxs73snmmhpgw4cjrpx16h3j1824 NarSize: 2241825 References: /build/TestClientSharedPathCommittedMidPush1053846507/001/store/l7gdb8pa2cprkw6kg99qf60513yixflv-shared-dep1826 CA: text:sha256:0y3yiwz4575khf83xg72r0n6695k8wsbqqj91imfk920fgsqmmak18272026/10/01 09:42:15 INFO Uploading 3 narinfos1828=== NAME TestClientFallsBackToClosures1829 client_pushes_test.go:112: Retrieved narinfo from S3:1830 StorePath: /build/TestClientFallsBackToClosures3842237889/001/store/g5lgzbbxgci4vv30q40k7ym3mmhpi98s-b1831 URL: nar/1rvp6kqcfhqiavwfgjvsp6h7r7w2piyw7064g3mn7qkai2bwngir.nar.zst1832 Compression: zstd1833 NarHash: sha256:1rvp6kqcfhqiavwfgjvsp6h7r7w2piyw7064g3mn7qkai2bwngir1834 NarSize: 2161835 References: /build/TestClientFallsBackToClosures3842237889/001/store/3bv0s0q8bdnfviv6kvb5nkc03bhvb1yk-shared-dep1836 CA: text:sha256:0fnhsxc6mhcr3117rpmdqibkz76q5qf5pa4dh6jhpi1c9ql0c09718372026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.42ms)18382026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)18392026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)18402026/10/01 09:42:15 WARN Failed to register uploaded object key=5l4zzah1nwskxq407wvhsv64i1bwjjbj.narinfo error="server returned 404: 404 page not found\n"18412026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete18422026/10/01 09:42:15 WARN Failed to register uploaded object key=qcxqikhcldvnzp4bc5fxjychlg6v0l5z.narinfo error="server returned 404: 404 page not found\n"18432026/10/01 09:42:15 WARN Failed to register uploaded object key=4i3mifj95mx4c014gi57npgikxsswjsf.narinfo error="server returned 404: 404 page not found\n"18442026-10-01 09:42:15.199 UTC [1065] ERROR: relation "goose_db_version" does not exist at character 3618452026-10-01 09:42:15.199 UTC [1065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18462026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)1847--- PASS: TestClientSharedPathCommittedMidPush (0.64s)1848=== CONT TestClientCADerivations18492026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes1850--- PASS: TestClientFallsBackToClosures (0.69s)1851=== CONT TestCacheConfigHandler1852=== RUN TestCacheConfigHandler/full_config,_no_issuer1853=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1854=== RUN TestCacheConfigHandler/no_cache_url_configured1855=== PAUSE TestCacheConfigHandler/no_cache_url_configured1856=== RUN TestCacheConfigHandler/no_signing_keys1857=== PAUSE TestCacheConfigHandler/no_signing_keys1858=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1859=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1860=== CONT TestCacheStatsHandler18612026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete18622026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.08ms)18632026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.93ms)18642026-10-01 09:42:15.203 UTC [1084] ERROR: relation "goose_db_version" does not exist at character 3618652026-10-01 09:42:15.203 UTC [1084] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18662026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.88ms)18672026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.25ms)18682026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.52ms)18692026/10/01 09:42:15 INFO Upload complete. (80ms)18702026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.69ms)18712026/10/01 09:42:15 goose: successfully migrated database to version: 202609231200001872=== NAME TestClientPushesUseOnePush1873 client_pushes_test.go:97: Retrieved narinfo from S3:1874 StorePath: /build/TestClientPushesUseOnePush357492065/001/store/4i3mifj95mx4c014gi57npgikxsswjsf-shared-dep1875 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1876 Compression: zstd1877 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821878 NarSize: 1361879 References: 1880 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18812026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)18822026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.97ms)18832026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000018842026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes18852026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.26ms)1886 client_pushes_test.go:97: Retrieved narinfo from S3:1887 StorePath: /build/TestClientPushesUseOnePush357492065/001/store/qcxqikhcldvnzp4bc5fxjychlg6v0l5z-a1888 URL: nar/0k8dmdrzdap91mzz8vnvwiyajamvq88x72z46kfd7qqgvpa1fkxh.nar.zst1889 Compression: zstd1890 NarHash: sha256:0k8dmdrzdap91mzz8vnvwiyajamvq88x72z46kfd7qqgvpa1fkxh1891 NarSize: 2081892 References: /build/TestClientPushesUseOnePush357492065/001/store/4i3mifj95mx4c014gi57npgikxsswjsf-shared-dep1893 CA: text:sha256:1318hnk7fc4r6w0vhiawa2lq9mqz7jnx18ssxx6wq0vh483cswpb18942026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.73ms)18952026/10/01 09:42:15 OK 1_commit_pending_closure.sql (3ms)18962026/10/01 09:42:15 OK 3_commit_push.sql (1.43ms)18972026/10/01 09:42:15 goose: up to current file version: 318982026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.89ms)18992026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.21ms)1900 client_pushes_test.go:97: Retrieved narinfo from S3:1901 StorePath: /build/TestClientPushesUseOnePush357492065/001/store/5l4zzah1nwskxq407wvhsv64i1bwjjbj-b1902 URL: nar/0k8dmdrzdap91mzz8vnvwiyajamvq88x72z46kfd7qqgvpa1fkxh.nar.zst1903 Compression: zstd1904 NarHash: sha256:0k8dmdrzdap91mzz8vnvwiyajamvq88x72z46kfd7qqgvpa1fkxh1905 NarSize: 2081906 References: /build/TestClientPushesUseOnePush357492065/001/store/4i3mifj95mx4c014gi57npgikxsswjsf-shared-dep1907 CA: text:sha256:1318hnk7fc4r6w0vhiawa2lq9mqz7jnx18ssxx6wq0vh483cswpb19082026-10-01 09:42:15.215 UTC [1107] ERROR: relation "goose_db_version" does not exist at character 3619092026-10-01 09:42:15.215 UTC [1107] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19102026/10/01 09:42:15 OK 3_commit_push.sql (1.93ms)19112026/10/01 09:42:15 goose: up to current file version: 319122026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.78ms)19132026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.95ms)1914--- PASS: TestClientPushesUseOnePush (0.68s)1915=== CONT TestReadProxyNarinfoAlreadyDecompressed19162026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (4.24ms)19172026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000019182026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete19192026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)19202026/10/01 09:42:15 OK 20241026095416_initial_model.sql (13ms)19212026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.7ms)19222026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)19232026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.5ms)19242026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.99ms)19252026/10/01 09:42:15 OK 3_commit_push.sql (1.82ms)19262026/10/01 09:42:15 goose: up to current file version: 31927--- PASS: TestReadProxyInvalidPath (0.39s)1928=== CONT TestGCEndsOnShutdown19292026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.75ms)19302026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (5.08ms)1931--- PASS: TestPush_CompleteCommitsEveryRoot (0.39s)1932=== CONT TestService_ReadAuthMiddleware19332026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)19342026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.83ms)19352026/10/01 09:42:15 OK 20241026095416_initial_model.sql (13.48ms)19362026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.03ms)19372026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)19382026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.97ms)19392026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes19402026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.38ms)19412026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000019422026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.64ms)19432026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.26ms)19442026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes19452026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.49ms)19462026-10-01 09:42:15.244 UTC [1133] ERROR: relation "goose_db_version" does not exist at character 3619472026-10-01 09:42:15.244 UTC [1133] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19482026/10/01 09:42:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19492026/10/01 09:42:15 INFO Uploading 8qvl3gx9y23r18d9mrdkay8gcv82x78m-test-script (136B)19502026/10/01 09:42:15 OK 2_object_stats_trigger.sql (8.01ms)19512026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (9.18ms)19522026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000019532026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (9.4ms)19542026/10/01 09:42:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19552026/10/01 09:42:15 INFO Uploading 6va4iph845hldmqcs95awgm2fsbv0y4l-unpinned-file.txt (128B)19562026/10/01 09:42:15 OK 3_commit_push.sql (1.88ms)19572026/10/01 09:42:15 goose: up to current file version: 319582026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.98ms)19592026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.91ms)1960--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.39s)1961=== CONT TestService_RequireScope_OIDC19622026/10/01 09:42:15 WARN Failed to register uploaded object key=log/s9r7cbfq01a0fdapxfbcc4zj5jv6hf4k-test-script.drv error="server returned 404: 404 page not found\n"19632026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19642026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19652026/10/01 09:42:15 WARN Failed to register uploaded object key=8qvl3gx9y23r18d9mrdkay8gcv82x78m.ls error="server returned 404: 404 page not found\n"19662026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.89ms)19672026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19682026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19692026/10/01 09:42:15 INFO Signed narinfos id=1 count=119702026/10/01 09:42:15 WARN Failed to register uploaded object key=6va4iph845hldmqcs95awgm2fsbv0y4l.ls error="server returned 404: 404 page not found\n"19712026/10/01 09:42:15 INFO Signed narinfos id=2 count=119722026/10/01 09:42:15 INFO Uploading 1 narinfos19732026/10/01 09:42:15 INFO Uploading 1 narinfos19742026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.6ms)19752026/10/01 09:42:15 OK 3_commit_push.sql (2.75ms)19762026/10/01 09:42:15 goose: up to current file version: 319772026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/2/complete19782026-10-01 09:42:15.261 UTC [1152] ERROR: relation "goose_db_version" does not exist at character 3619792026-10-01 09:42:15.261 UTC [1152] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19802026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete19812026/10/01 09:42:15 WARN Failed to register uploaded object key=6va4iph845hldmqcs95awgm2fsbv0y4l.narinfo error="server returned 404: 404 page not found\n"19822026/10/01 09:42:15 WARN Failed to register uploaded object key=8qvl3gx9y23r18d9mrdkay8gcv82x78m.narinfo error="server returned 404: 404 page not found\n"19832026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.34ms)19842026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000019852026/10/01 09:42:15 INFO Upload complete. (53ms)19862026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.54ms)19872026/10/01 09:42:15 OK 20241026095416_initial_model.sql (13.24ms)19882026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.85ms)19892026/10/01 09:42:15 OK 3_commit_push.sql (1.36ms)19902026/10/01 09:42:15 goose: up to current file version: 319912026/10/01 09:42:15 INFO Upload complete. (67ms)19922026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)19932026/10/01 09:42:15 INFO Aborted multipart uploads count=0 kept=01994=== NAME TestClientWithDependencies1995 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1354658245/001/store) requires matching store prefix19962026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.65ms)19972026/10/01 09:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period1998--- PASS: TestClientWithDependencies (0.65s)1999=== CONT TestPendingCleanupUsesOneCutoff20002026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes20012026/10/01 09:42:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20022026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)20032026-10-01 09:42:15.278 UTC [1154] ERROR: relation "goose_db_version" does not exist at character 3620042026-10-01 09:42:15.278 UTC [1154] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20052026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.55ms)20062026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)20072026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.3ms)20082026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.75ms)20092026-10-01 09:42:15.284 UTC [1156] ERROR: relation "goose_db_version" does not exist at character 3620102026-10-01 09:42:15.284 UTC [1156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20112026/10/01 09:42:15 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=020122026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.98ms)20132026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.78ms)20142026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000020152026/10/01 09:42:15 INFO Vacuumed table table=pending_closures20162026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)20172026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.69ms)20182026/10/01 09:42:15 INFO Vacuumed table table=pending_objects20192026/10/01 09:42:15 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLjExMGI1YmVhLTdkNzAtNDExNS1hMmUxLTAzMDgzNjM5ODYyMXgxNzkwODQ3NzM0ODgyMTM4MzA1 error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20202026/10/01 09:42:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Mjg3ZWE1MzUtMzU4Mi00MzAzLWE5ZTYtM2JlYjM2Nzg3OWUwLmJmY2Y5MjFiLWNmNDktNGU4Ny05MDIyLTE0NWYzYmU0OGI1OHgxNzkwODQ3NzM0ODc0OTExODU5 parts=1220212026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.22ms)20222026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.66ms)20232026/10/01 09:42:15 INFO Vacuumed table table=multipart_uploads20242026/10/01 09:42:15 OK 3_commit_push.sql (1.67ms)20252026/10/01 09:42:15 goose: up to current file version: 320262026/10/01 09:42:15 INFO Received cleanup request method=DELETE path=/api/pending_closures20272026/10/01 09:42:15 INFO Aborted multipart uploads count=1 kept=020282026/10/01 09:42:15 OK 20241026095416_initial_model.sql (16.75ms)20292026/10/01 09:42:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures20302026/10/01 09:42:15 INFO Garbage collection started20312026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (10.17ms)20322026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.35ms)2033--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.43s)2034=== CONT TestService_AuthMiddleware_MTLSBoundSubjects20352026/10/01 09:42:15 INFO Vacuumed table table=closures2036--- PASS: TestRedundantMultipartUpload (1.30s)2037=== CONT TestService_AuthMiddleware_OIDC20382026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)20392026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)20402026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (3.17ms)20412026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000020422026/10/01 09:42:15 INFO Vacuumed table table=objects20432026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/2/complete20442026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.63ms)20452026/10/01 09:42:15 OK 1_commit_pending_closure.sql (3.15ms)20462026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.76ms)2047--- PASS: TestReadProxyConditionalGet (0.40s)2048=== CONT TestIsValidCachePath2049=== RUN TestIsValidCachePath/narinfo2050=== PAUSE TestIsValidCachePath/narinfo2051=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2052=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2053=== RUN TestIsValidCachePath/nar_zst2054=== PAUSE TestIsValidCachePath/nar_zst2055=== RUN TestIsValidCachePath/nar_xz2056=== PAUSE TestIsValidCachePath/nar_xz20572026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.17ms)2058--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.50s)2059=== CONT TestService_AuthMiddleware_MTLSProxyHeader2060=== RUN TestIsValidCachePath/nar_bz22061=== PAUSE TestIsValidCachePath/nar_bz22062=== RUN TestIsValidCachePath/nar_uncompressed2063=== PAUSE TestIsValidCachePath/nar_uncompressed2064=== RUN TestIsValidCachePath/ls2065=== PAUSE TestIsValidCachePath/ls2066=== RUN TestIsValidCachePath/log2067=== PAUSE TestIsValidCachePath/log2068=== RUN TestIsValidCachePath/realisation2069=== PAUSE TestIsValidCachePath/realisation2070=== RUN TestIsValidCachePath/nix-cache-info2071=== PAUSE TestIsValidCachePath/nix-cache-info2072=== RUN TestIsValidCachePath/index.html2073=== PAUSE TestIsValidCachePath/index.html2074=== RUN TestIsValidCachePath/traversal_parent2075=== PAUSE TestIsValidCachePath/traversal_parent2076=== RUN TestIsValidCachePath/traversal_in_middle2077=== PAUSE TestIsValidCachePath/traversal_in_middle2078=== RUN TestIsValidCachePath/invalid_char_e2079=== PAUSE TestIsValidCachePath/invalid_char_e2080=== RUN TestIsValidCachePath/invalid_char_u2081=== PAUSE TestIsValidCachePath/invalid_char_u2082=== RUN TestIsValidCachePath/random_path2083=== PAUSE TestIsValidCachePath/random_path2084=== RUN TestIsValidCachePath/empty2085=== PAUSE TestIsValidCachePath/empty2086=== RUN TestIsValidCachePath/leading_slash2087=== PAUSE TestIsValidCachePath/leading_slash2088=== RUN TestIsValidCachePath/wrong_extension2089=== PAUSE TestIsValidCachePath/wrong_extension2090=== RUN TestIsValidCachePath/short_hash2091=== PAUSE TestIsValidCachePath/short_hash2092=== CONT TestProxyHeadersOnlyTrustedOnSocket20932026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)20942026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)20952026-10-01 09:42:15.314 UTC [1179] ERROR: relation "goose_db_version" does not exist at character 3620962026-10-01 09:42:15.314 UTC [1179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20972026/10/01 09:42:15 OK 3_commit_push.sql (2.1ms)20982026-10-01 09:42:15.314 UTC [1180] ERROR: relation "goose_db_version" does not exist at character 3620992026-10-01 09:42:15.314 UTC [1180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21002026/10/01 09:42:15 goose: up to current file version: 321012026/10/01 09:42:15 INFO Aborted multipart uploads count=0 kept=021022026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.64ms)21032026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.19ms)21042026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.54ms)21052026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.59ms)21062026/10/01 09:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.87ms)21082026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000021092026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (3.19ms)21102026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000021112026/10/01 09:42:15 OK 1_commit_pending_closure.sql (3.19ms)21122026-10-01 09:42:15.326 UTC [1187] ERROR: relation "goose_db_version" does not exist at character 3621132026-10-01 09:42:15.326 UTC [1187] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21142026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.52ms)21152026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.46ms)21162026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.06ms)21172026/10/01 09:42:15 OK 3_commit_push.sql (2.06ms)21182026/10/01 09:42:15 goose: up to current file version: 321192026/10/01 09:42:15 OK 3_commit_push.sql (1.52ms)21202026/10/01 09:42:15 goose: up to current file version: 32121--- PASS: TestReadProxyHead (0.40s)2122=== CONT TestMetricsInventory21232026/10/01 09:42:15 OK 20241026095416_initial_model.sql (13.45ms)21242026/10/01 09:42:15 OK 20241026095416_initial_model.sql (14.9ms)21252026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)21262026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)21272026/10/01 09:42:15 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=021282026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.35ms)21292026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.28ms)21302026/10/01 09:42:15 INFO Vacuumed table table=pending_closures21312026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.74ms)21322026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.04ms)21332026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)21342026/10/01 09:42:15 INFO Vacuumed table table=pending_objects21352026/10/01 09:42:15 INFO Vacuumed table table=multipart_uploads21362026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)21372026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.67ms)21382026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.39ms)21392026/10/01 09:42:15 INFO Vacuumed table table=closures21402026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.21ms)21412026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.92ms)21422026/10/01 09:42:15 INFO Vacuumed table table=objects21432026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.03ms)21442026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures21452026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.65ms)21462026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000021472026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.99ms)21482026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000021492026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)21502026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.27ms)21512026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.25ms)21522026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.42ms)21532026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.77ms)2154--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.33s)2155=== CONT TestCreatePin_ReservedPins21562026/10/01 09:42:15 OK 3_commit_push.sql (1.37ms)21572026/10/01 09:42:15 goose: up to current file version: 321582026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.21ms)21592026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.53ms)21602026/10/01 09:42:15 OK 3_commit_push.sql (2.03ms)21612026/10/01 09:42:15 goose: up to current file version: 321622026-10-01 09:42:15.364 UTC [1190] ERROR: relation "goose_db_version" does not exist at character 3621632026-10-01 09:42:15.364 UTC [1190] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21642026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (8.1ms)21652026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000021662026/10/01 09:42:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39467/oidc21672026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.48ms)21682026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.75ms)21692026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures21702026/10/01 09:42:15 OK 3_commit_push.sql (1.4ms)21712026/10/01 09:42:15 goose: up to current file version: 32172--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.88s)2173=== CONT TestOrphanedObjectsGCStressTest21742026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.18ms)21752026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)21762026-10-01 09:42:15.389 UTC [1194] ERROR: relation "goose_db_version" does not exist at character 3621772026-10-01 09:42:15.389 UTC [1194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21782026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.38ms)21792026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)21802026/10/01 09:42:15 INFO Aborted multipart uploads count=0 kept=021812026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures21822026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.26ms)21832026-10-01 09:42:15.397 UTC [1197] ERROR: relation "goose_db_version" does not exist at character 3621842026-10-01 09:42:15.397 UTC [1197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21852026/10/01 09:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period21862026-10-01 09:42:15.399 UTC [1198] ERROR: relation "goose_db_version" does not exist at character 3621872026-10-01 09:42:15.399 UTC [1198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21882026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.93ms)21892026/10/01 09:42:15 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=021902026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.24ms)21912026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000021922026/10/01 09:42:15 INFO Vacuumed table table=pending_closures21932026/10/01 09:42:15 OK 1_commit_pending_closure.sql (3ms)21942026/10/01 09:42:15 INFO Vacuumed table table=pending_objects21952026/10/01 09:42:15 INFO Vacuumed table table=multipart_uploads21962026/10/01 09:42:15 INFO Vacuumed table table=closures21972026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.25ms)21982026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.8ms)21992026/10/01 09:42:15 OK 3_commit_push.sql (1.94ms)22002026/10/01 09:42:15 goose: up to current file version: 322012026/10/01 09:42:15 INFO Vacuumed table table=objects22022026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)22032026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.62ms)22042026-10-01 09:42:15.415 UTC [1199] ERROR: relation "goose_db_version" does not exist at character 3622052026-10-01 09:42:15.415 UTC [1199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22062026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.98ms)22072026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.07ms)22082026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)22092026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)2210--- PASS: TestGCSweepSkipsPendingObjects (0.35s)2211=== CONT TestParseSingleRange2212=== RUN TestParseSingleRange/none2213=== PAUSE TestParseSingleRange/none2214=== RUN TestParseSingleRange/unknown_unit2215=== PAUSE TestParseSingleRange/unknown_unit22162026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)2217=== RUN TestParseSingleRange/multi-range_ignored2218=== PAUSE TestParseSingleRange/multi-range_ignored2219=== RUN TestParseSingleRange/malformed_no_dash2220=== PAUSE TestParseSingleRange/malformed_no_dash2221=== RUN TestParseSingleRange/malformed_both_empty2222=== PAUSE TestParseSingleRange/malformed_both_empty2223=== RUN TestParseSingleRange/malformed_end_before_start2224=== PAUSE TestParseSingleRange/malformed_end_before_start2225=== RUN TestParseSingleRange/closed2226=== PAUSE TestParseSingleRange/closed2227=== RUN TestParseSingleRange/open-ended2228=== PAUSE TestParseSingleRange/open-ended2229=== RUN TestParseSingleRange/end_clamped_to_size2230=== PAUSE TestParseSingleRange/end_clamped_to_size2231=== RUN TestParseSingleRange/suffix2232=== PAUSE TestParseSingleRange/suffix2233=== RUN TestParseSingleRange/suffix_exceeds_size2234=== PAUSE TestParseSingleRange/suffix_exceeds_size2235=== RUN TestParseSingleRange/single_byte2236=== PAUSE TestParseSingleRange/single_byte2237=== RUN TestParseSingleRange/start_past_EOF2238=== PAUSE TestParseSingleRange/start_past_EOF2239=== RUN TestParseSingleRange/start_far_past_EOF2240=== PAUSE TestParseSingleRange/start_far_past_EOF2241=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded22422026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.78ms)22432026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.94ms)22442026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.6ms)22452026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.53ms)22462026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)22472026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)22482026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.95ms)22492026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000022502026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.45ms)22512026/10/01 09:42:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34671/oidc22522026/10/01 09:42:15 OK 1_commit_pending_closure.sql (9.03ms)2253--- PASS: TestService_ReadScope_PublicByDefault (0.34s)2254=== CONT TestOrphanedObjectsGC22552026/10/01 09:42:15 OK 20260905000000_add_claims.sql (10.6ms)22562026/10/01 09:42:15 OK 20241026095416_initial_model.sql (15.54ms)22572026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.72ms)22582026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (8.71ms)22592026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)22602026/10/01 09:42:15 OK 3_commit_push.sql (1.58ms)22612026/10/01 09:42:15 goose: up to current file version: 322622026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.29ms)22632026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000022642026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.32ms)22652026/10/01 09:42:15 OK 20251218171726_add_pins.sql (2.88ms)22662026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.28ms)22672026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (3.03ms)22682026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000022692026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.69ms)22702026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)22712026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.22ms)22722026/10/01 09:42:15 OK 3_commit_push.sql (1.45ms)22732026/10/01 09:42:15 goose: up to current file version: 322742026/10/01 09:42:15 OK 2_object_stats_trigger.sql (788.41µs)22752026/10/01 09:42:15 OK 3_commit_push.sql (1.03ms)22762026/10/01 09:42:15 goose: up to current file version: 322772026/10/01 09:42:15 INFO Aborted multipart uploads count=0 kept=022782026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.23ms)22792026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.62ms)22802026-10-01 09:42:15.451 UTC [1207] ERROR: relation "goose_db_version" does not exist at character 3622812026-10-01 09:42:15.451 UTC [1207] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22822026/10/01 09:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period22832026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.13ms)22842026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000022852026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.71ms)22862026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.53ms)22872026/10/01 09:42:15 OK 3_commit_push.sql (1.25ms)22882026/10/01 09:42:15 goose: up to current file version: 322892026-10-01 09:42:15.460 UTC [1208] ERROR: relation "goose_db_version" does not exist at character 3622902026-10-01 09:42:15.460 UTC [1208] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22912026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures22922026/10/01 09:42:15 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=022932026/10/01 09:42:15 INFO Vacuumed table table=pending_closures22942026/10/01 09:42:15 INFO Vacuumed table table=pending_objects22952026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.59ms)22962026/10/01 09:42:15 INFO Vacuumed table table=multipart_uploads22972026/10/01 09:42:15 INFO Vacuumed table table=closures2298--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.37s)2299=== CONT TestPresentNotReportedWhileGCDeletesClosure23002026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)23012026/10/01 09:42:15 INFO Vacuumed table table=objects2302--- PASS: TestGCSweepDeliversEachKeyOnce (0.40s)2303=== CONT TestMultipartCleanup23042026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.68ms)23052026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.25ms)23062026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)23072026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)23082026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.68ms)23092026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.7ms)23102026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.08ms)23112026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)23122026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (3.15ms)23132026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000023142026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.3ms)23152026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.22ms)23162026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.64ms)23172026/10/01 09:42:15 OK 3_commit_push.sql (2.12ms)23182026/10/01 09:42:15 goose: up to current file version: 323192026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.11ms)23202026-10-01 09:42:15.500 UTC [1214] ERROR: relation "goose_db_version" does not exist at character 3623212026-10-01 09:42:15.500 UTC [1214] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23222026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (8.94ms)23232026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000023242026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.65ms)23252026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.42ms)23262026/10/01 09:42:15 OK 3_commit_push.sql (1.28ms)23272026/10/01 09:42:15 goose: up to current file version: 32328--- PASS: TestReadProxyNarStreaming (0.36s)2329=== CONT TestObjectStatsTrigger23302026-10-01 09:42:15.517 UTC [1215] ERROR: relation "goose_db_version" does not exist at character 3623312026-10-01 09:42:15.517 UTC [1215] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23322026-10-01 09:42:15.518 UTC [1217] ERROR: relation "goose_db_version" does not exist at character 3623332026-10-01 09:42:15.518 UTC [1217] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23342026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.88ms)23352026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)23362026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.03ms)2337=== NAME TestClientIntegration2338 client_integration_test.go:286: Created store path: /build/TestClientIntegration3221082149/002/store/dm63r2bdf86lc61fzdximkjvprr3qapa-test-file.txt2339--- PASS: TestReadProxy404 (0.36s)2340=== CONT TestPresentReportsOnlyClosureRoots23412026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.92ms)23422026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.1ms)23432026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.77ms)23442026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.12ms)23452026/10/01 09:42:15 OK 20241026095416_initial_model.sql (12.06ms)23462026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)23472026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.45ms)23482026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000023492026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)23502026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.25ms)23512026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.57ms)23522026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.46ms)23532026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.58ms)23542026/10/01 09:42:15 OK 3_commit_push.sql (1.46ms)23552026/10/01 09:42:15 goose: up to current file version: 323562026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)23572026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)23582026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.31ms)23592026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.51ms)23602026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (1.75ms)23612026-10-01 09:42:15.552 UTC [1238] ERROR: relation "goose_db_version" does not exist at character 3623622026-10-01 09:42:15.552 UTC [1238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23632026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.89ms)23642026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000023652026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.87ms)23662026-10-01 09:42:15.554 UTC [1239] ERROR: relation "goose_db_version" does not exist at character 3623672026-10-01 09:42:15.554 UTC [1239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23682026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.65ms)23692026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (3.17ms)23702026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000023712026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.08ms)2372--- PASS: TestCacheStatsHandler (0.36s)2373=== CONT TestServerTLSConfig2374=== RUN TestServerTLSConfig/no_client_CA2375=== PAUSE TestServerTLSConfig/no_client_CA2376=== RUN TestServerTLSConfig/missing_CA_file2377=== PAUSE TestServerTLSConfig/missing_CA_file2378=== RUN TestServerTLSConfig/not_a_PEM_file2379=== PAUSE TestServerTLSConfig/not_a_PEM_file23802026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.23ms)2381=== CONT TestService_NativeMTLS23822026/10/01 09:42:15 OK 3_commit_push.sql (1.34ms)23832026/10/01 09:42:15 goose: up to current file version: 323842026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.94ms)23852026/10/01 09:42:15 OK 3_commit_push.sql (1.26ms)23862026/10/01 09:42:15 goose: up to current file version: 323872026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.04ms)23882026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)23892026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.96ms)23902026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)23912026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.17ms)23922026/10/01 09:42:15 OK 20251218171726_add_pins.sql (10.54ms)23932026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (10.82ms)23942026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)23952026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.38ms)23962026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.64ms)23972026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.6ms)2398--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.38s)2399=== CONT TestCacheConfigHandlerMaxNarSize2400--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2401=== CONT TestCommitRacingPendingCleanupKeepsObjects24022026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.66ms)24032026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000024042026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.78ms)24052026-10-01 09:42:15.596 UTC [1261] ERROR: relation "goose_db_version" does not exist at character 3624062026-10-01 09:42:15.596 UTC [1261] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24072026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.06ms)24082026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.27ms)24092026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000024102026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.13ms)24112026/10/01 09:42:15 OK 3_commit_push.sql (699.45µs)24122026/10/01 09:42:15 goose: up to current file version: 324132026/10/01 09:42:15 OK 1_commit_pending_closure.sql (1.81ms)24142026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes24152026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.75ms)24162026/10/01 09:42:15 OK 3_commit_push.sql (1.07ms)24172026/10/01 09:42:15 goose: up to current file version: 324182026/10/01 09:42:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24192026/10/01 09:42:15 INFO Uploading dm63r2bdf86lc61fzdximkjvprr3qapa-test-file.txt (152B)2420--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.55s)2421=== CONT TestCreatePendingClosureRejectsOversizedNAR24222026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures2423--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2424=== CONT TestNARDeduplicationMetadataUploadBug24252026-10-01 09:42:15.609 UTC [1297] ERROR: relation "goose_db_version" does not exist at character 3624262026-10-01 09:42:15.609 UTC [1297] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24272026/10/01 09:42:15 WARN Failed to register uploaded object key=dm63r2bdf86lc61fzdximkjvprr3qapa.ls error="server returned 404: 404 page not found\n"24282026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24292026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"24302026/10/01 09:42:15 INFO Signed narinfos id=1 count=124312026/10/01 09:42:15 INFO Uploading 1 narinfos24322026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.43ms)24332026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete24342026/10/01 09:42:15 WARN Failed to register uploaded object key=dm63r2bdf86lc61fzdximkjvprr3qapa.narinfo error="server returned 404: 404 page not found\n"2435--- PASS: TestGCEndsOnShutdown (0.39s)2436=== CONT TestGenerateLandingPage24372026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)2438--- PASS: TestGenerateLandingPage (0.00s)2439=== CONT TestService_readinessHandler24402026/10/01 09:42:15 OK 20251218171726_add_pins.sql (4.09ms)24412026/10/01 09:42:15 INFO Upload complete. (62ms)24422026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)24432026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.25ms)24442026/10/01 09:42:15 OK 20241026095416_initial_model.sql (13.66ms)2445--- PASS: TestService_ReadAuthMiddleware (0.40s)2446=== CONT TestProxyWriteTimeout/narinfo2447=== CONT TestProxyWriteTimeout/unknown_size2448=== CONT TestProxyWriteTimeout/10_GiB_nar2449=== CONT TestProxyWriteTimeout/1_GiB_nar2450--- PASS: TestProxyWriteTimeout (0.01s)2451 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2452 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2453 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2454 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2455=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows24562026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)24572026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (6ms)24582026-10-01 09:42:15.636 UTC [1304] ERROR: relation "goose_db_version" does not exist at character 3624592026-10-01 09:42:15.636 UTC [1304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24602026/10/01 09:42:15 OK 20251218171726_add_pins.sql (5.62ms)24612026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (4.26ms)24622026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000024632026/10/01 09:42:15 OK 1_commit_pending_closure.sql (4.43ms)24642026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (6.39ms)24652026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.83ms)24662026/10/01 09:42:15 OK 3_commit_push.sql (2.78ms)24672026/10/01 09:42:15 goose: up to current file version: 324682026/10/01 09:42:15 OK 20260905000000_add_claims.sql (7.44ms)24692026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.97ms)24702026/10/01 09:42:15 OK 20241026095416_initial_model.sql (15.31ms)24712026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (4.89ms)24722026/10/01 09:42:15 goose: successfully migrated database to version: 202609231200002473=== NAME TestClientCADerivations2474 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3802157080/001/store/5qh9dx1aqrdgr31vcwwi70l7q2i52bib-ca-test24752026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (4.68ms)24762026/10/01 09:42:15 OK 1_commit_pending_closure.sql (14.41ms)24772026/10/01 09:42:15 INFO All 1 paths already cached24782026/10/01 09:42:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35649/oidc2479=== NAME TestClientIntegration24802026/10/01 09:42:15 OK 20251218171726_add_pins.sql (13.59ms)2481 client_integration_test.go:312: Retrieved narinfo from S3:2482 StorePath: /build/TestClientIntegration3221082149/002/store/dm63r2bdf86lc61fzdximkjvprr3qapa-test-file.txt2483 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2484 Compression: zstd2485 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12486 NarSize: 1522487 References: 2488 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk124892026/10/01 09:42:15 OK 2_object_stats_trigger.sql (2.72ms)24902026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures24912026/10/01 09:42:15 OK 3_commit_push.sql (1.43ms)24922026/10/01 09:42:15 goose: up to current file version: 32493 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2494 client_integration_test.go:313: Decompressed .ls content (64 bytes):2495 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2496 client_integration_test.go:316: Testing garbage collection...24972026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)24982026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.46ms)24992026-10-01 09:42:15.688 UTC [1344] ERROR: relation "goose_db_version" does not exist at character 3625002026-10-01 09:42:15.688 UTC [1344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25012026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.87ms)25022026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (3.09ms)25032026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000025042026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures25052026-10-01 09:42:15.694 UTC [1346] ERROR: relation "goose_db_version" does not exist at character 3625062026-10-01 09:42:15.694 UTC [1346] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25072026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.7ms)25082026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.88ms)25092026/10/01 09:42:15 OK 3_commit_push.sql (1.34ms)25102026/10/01 09:42:15 goose: up to current file version: 32511=== NAME TestClientCADerivations2512 client_ca_test.go:139: Found 1 dependencies (including self)25132026/10/01 09:42:15 INFO Received cleanup request method=DELETE path=/api/pending_closures25142026/10/01 09:42:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"25152026/10/01 09:42:15 WARN mTLS auth: bound subjects configured but subject DN unavailable25162026/10/01 09:42:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2517--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.40s)2518=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check25192026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.68ms)25202026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)25212026-10-01 09:42:15.708 UTC [1364] ERROR: relation "goose_db_version" does not exist at character 3625222026-10-01 09:42:15.708 UTC [1364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25232026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.39ms)25242026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.76ms)25252026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)25262026/10/01 09:42:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures25272026/10/01 09:42:15 INFO Garbage collection started25282026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)25292026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.55ms)25302026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.12ms)25312026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)25322026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.81ms)25332026-10-01 09:42:15.723 UTC [1385] ERROR: relation "goose_db_version" does not exist at character 3625342026-10-01 09:42:15.723 UTC [1385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25352026/10/01 09:42:15 INFO Aborted multipart uploads count=0 kept=025362026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.66ms)25372026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.4ms)25382026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000025392026/10/01 09:42:15 OK 20241026095416_initial_model.sql (11.49ms)2540--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.41s)2541=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info25422026/10/01 09:42:15 INFO Received uploads request method=POST path=/2543=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key25442026/10/01 09:42:15 INFO Received complete multipart upload request method=POST path=/2545=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25462026/10/01 09:42:15 INFO Received uploads request method=POST path=/2547=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25482026/10/01 09:42:15 INFO Received request for more parts method=POST path=/2549--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2550 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2551 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2552 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2553 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2554=== CONT TestIsValidUploadKey/absolute2555=== CONT TestIsValidUploadKey/narinfo2556=== CONT TestIsValidUploadKey/traversal_nar2557=== CONT TestIsValidUploadKey/traversal2558=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2559=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2560=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2561=== CONT TestIsValidUploadKey/build_log_home-manager_file2562=== CONT TestIsValidUploadKey/build_log2563=== CONT TestIsValidUploadKey/listing2564=== CONT TestIsValidUploadKey/nar_plain2565=== CONT TestIsValidUploadKey/nar_xz2566=== CONT TestIsValidUploadKey/build_log_plus_in_name2567=== CONT TestIsValidUploadKey/nar_zst2568=== CONT TestIsValidUploadKey/index.html25692026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (3.15ms)2570=== CONT TestIsValidUploadKey/unknown_type2571=== CONT TestIsValidUploadKey/build_log_question_mark2572=== CONT TestIsValidUploadKey/build_log_equals2573=== CONT TestIsValidUploadKey/empty_key2574=== CONT TestIsValidUploadKey/nix-cache-info2575=== CONT TestIsValidUploadKey/realisation_plus_in_output2576=== CONT TestIsValidUploadKey/realisation2577--- PASS: TestIsValidUploadKey (0.06s)2578 --- PASS: TestIsValidUploadKey/absolute (0.00s)2579 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2580 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2581 --- PASS: TestIsValidUploadKey/traversal (0.00s)2582 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2583 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2584 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2585 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2586 --- PASS: TestIsValidUploadKey/build_log (0.00s)2587 --- PASS: TestIsValidUploadKey/listing (0.00s)2588 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2589 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2590 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2591 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2592 --- PASS: TestIsValidUploadKey/index.html (0.00s)2593 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2594 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2595 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2596 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2597 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2598 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2599 --- PASS: TestIsValidUploadKey/realisation (0.00s)2600=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts26012026/10/01 09:42:15 INFO Received request for more parts method=POST path=/26022026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)26032026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.62ms)26042026/10/01 09:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period26052026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.71ms)26062026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.89ms)26072026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000026082026/10/01 09:42:15 OK 3_commit_push.sql (1.39ms)26092026/10/01 09:42:15 goose: up to current file version: 326102026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.99ms)26112026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.45ms)26122026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.4ms)26132026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)26142026/10/01 09:42:15 OK 3_commit_push.sql (1.68ms)26152026/10/01 09:42:15 goose: up to current file version: 326162026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.42ms)26172026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.66ms)26182026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.79ms)26192026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)26202026/10/01 09:42:15 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=026212026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.54ms)26222026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000026232026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.12ms)26242026/10/01 09:42:15 INFO Vacuumed table table=pending_closures26252026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.33ms)26262026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.39ms)26272026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)26282026/10/01 09:42:15 INFO Vacuumed table table=pending_objects26292026/10/01 09:42:15 OK 3_commit_push.sql (1.02ms)26302026/10/01 09:42:15 goose: up to current file version: 326312026/10/01 09:42:15 INFO Vacuumed table table=multipart_uploads26322026/10/01 09:42:15 INFO Starting HTTP server address=127.0.0.1:4604126332026/10/01 09:42:15 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1365698747/001/proxy.sock26342026/10/01 09:42:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"26352026/10/01 09:42:15 INFO Shutdown signal received, draining in-flight requests timeout=10s2636--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.44s)2637=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart26382026/10/01 09:42:15 INFO Received complete multipart upload request method=POST path=/26392026/10/01 09:42:15 INFO Vacuumed table table=closures26402026/10/01 09:42:15 OK 20260905000000_add_claims.sql (4.03ms)26412026/10/01 09:42:15 INFO Vacuumed table table=objects26422026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.33ms)26432026-10-01 09:42:15.756 UTC [1404] ERROR: relation "goose_db_version" does not exist at character 3626442026-10-01 09:42:15.756 UTC [1404] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26452026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.76ms)26462026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000026472026/10/01 09:42:15 OK 1_commit_pending_closure.sql (1.94ms)26482026/10/01 09:42:15 OK 2_object_stats_trigger.sql (7.26ms)26492026/10/01 09:42:15 OK 3_commit_push.sql (988.55µs)26502026/10/01 09:42:15 goose: up to current file version: 326512026/10/01 09:42:15 OK 20241026095416_initial_model.sql (9.05ms)26522026-10-01 09:42:15.778 UTC [1406] ERROR: relation "goose_db_version" does not exist at character 3626532026-10-01 09:42:15.778 UTC [1406] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26542026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)26552026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3.3ms)2656--- PASS: TestMetricsInventory (0.45s)2657=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure26582026/10/01 09:42:15 INFO Received uploads request method=POST path=/26592026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)2660=== CONT TestPush_RejectsBadRequests/no_roots26612026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes2662=== CONT TestPush_RejectsBadRequests/no_objects26632026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes2664=== CONT TestPush_RejectsBadRequests/root_not_in_objects26652026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes2666=== CONT TestPush_RejectsBadRequests/bad_root26672026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes2668=== CONT TestResolveDBConnectionString/flag_wins2669--- PASS: TestPush_RejectsBadRequests (0.34s)2670 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2671 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2672 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2673 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2674=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2675=== CONT TestResolveDBConnectionString/nothing_configured2676=== CONT TestResolveDBConnectionString/missing_file_is_an_error2677=== CONT TestResolveDBConnectionString/file_when_flag_empty2678=== CONT TestClientErrorHandling/InvalidStorePath2679--- PASS: TestResolveDBConnectionString (0.00s)2680 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2681 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2682 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2683 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2684 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2685=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2686=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token26872026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.34ms)2688=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2689=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2690=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2691=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2692=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2693=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2694=== CONT TestClientErrorHandling/ServerNotAvailable26952026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (2.65ms)26962026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.48ms)26972026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.41ms)26982026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000026992026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)27002026/10/01 09:42:15 OK 1_commit_pending_closure.sql (1.64ms)27012026/10/01 09:42:15 OK 2_object_stats_trigger.sql (781.19µs)27022026/10/01 09:42:15 OK 3_commit_push.sql (522.04µs)27032026/10/01 09:42:15 goose: up to current file version: 327042026/10/01 09:42:15 OK 20251218171726_add_pins.sql (2.66ms)27052026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.45ms)27062026/10/01 09:42:15 OK 20260905000000_add_claims.sql (3.6ms)27072026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (1.97ms)27082026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (2.31ms)27092026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000027102026/10/01 09:42:15 INFO Received push request method=POST path=/api/pushes27112026/10/01 09:42:15 OK 1_commit_pending_closure.sql (2.55ms)27122026/10/01 09:42:15 OK 2_object_stats_trigger.sql (1.4ms)2713=== CONT TestClientErrorHandling/InvalidAuthToken27142026/10/01 09:42:15 OK 3_commit_push.sql (1.09ms)27152026/10/01 09:42:15 goose: up to current file version: 327162026/10/01 09:42:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27172026/10/01 09:42:15 INFO Uploading 5qh9dx1aqrdgr31vcwwi70l7q2i52bib-ca-test (144B)27182026/10/01 09:42:15 WARN Failed to register uploaded object key=log/n2ycpg05qm0bkjp5flvawmdcrikrbwh4-ca-test.drv error="server returned 404: 404 page not found\n"27192026/10/01 09:42:15 WARN Failed to register uploaded object key=5qh9dx1aqrdgr31vcwwi70l7q2i52bib.ls error="server returned 404: 404 page not found\n"27202026/10/01 09:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27212026/10/01 09:42:15 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"27222026/10/01 09:42:15 INFO Signed narinfos id=1 count=127232026/10/01 09:42:15 INFO Uploading 1 narinfos27242026/10/01 09:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete27252026/10/01 09:42:15 WARN Failed to register uploaded object key=5qh9dx1aqrdgr31vcwwi70l7q2i52bib.narinfo error="server returned 404: 404 page not found\n"27262026/10/01 09:42:15 INFO Upload complete. (108ms)27272026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures2728=== NAME TestClientCADerivations2729 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3802157080/001/store/5qh9dx1aqrdgr31vcwwi70l7q2i52bib-ca-test2730 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2731 Compression: zstd2732 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2733 NarSize: 1442734 References: 2735 Deriver: /build/TestClientCADerivations3802157080/001/store/n2ycpg05qm0bkjp5flvawmdcrikrbwh4-ca-test.drv2736 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2737 client_ca_test.go:185: Checking for realisation files in S3...2738 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2739 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache27402026/10/01 09:42:15 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/present27412026-10-01 09:42:15.860 UTC [1465] ERROR: relation "goose_db_version" does not exist at character 3627422026-10-01 09:42:15.860 UTC [1465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2743--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.45s)2744=== CONT TestCacheConfigHandler/full_config,_no_issuer2745=== CONT TestCacheConfigHandler/no_signing_keys2746=== CONT TestCacheConfigHandler/no_cache_url_configured2747=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2748--- PASS: TestCacheConfigHandler (0.00s)2749 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2750 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2751 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2752 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2753=== CONT TestIsValidCachePath/narinfo2754=== CONT TestIsValidCachePath/index.html2755=== CONT TestIsValidCachePath/nix-cache-info2756=== CONT TestIsValidCachePath/realisation2757=== CONT TestIsValidCachePath/log2758=== CONT TestIsValidCachePath/ls2759=== CONT TestIsValidCachePath/nar_uncompressed2760=== CONT TestIsValidCachePath/nar_bz22761=== CONT TestIsValidCachePath/nar_xz2762=== CONT TestIsValidCachePath/nar_zst2763=== CONT TestIsValidCachePath/traversal_parent2764=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2765=== CONT TestIsValidCachePath/wrong_extension2766=== CONT TestIsValidCachePath/short_hash2767=== CONT TestIsValidCachePath/invalid_char_u2768=== CONT TestIsValidCachePath/empty2769=== CONT TestIsValidCachePath/random_path2770=== CONT TestIsValidCachePath/leading_slash2771=== CONT TestIsValidCachePath/invalid_char_e2772=== CONT TestIsValidCachePath/traversal_in_middle2773--- PASS: TestIsValidCachePath (0.00s)2774 --- PASS: TestIsValidCachePath/narinfo (0.00s)2775 --- PASS: TestIsValidCachePath/index.html (0.00s)2776 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2777 --- PASS: TestIsValidCachePath/realisation (0.00s)2778 --- PASS: TestIsValidCachePath/log (0.00s)2779 --- PASS: TestIsValidCachePath/ls (0.00s)2780 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2781 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2782 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2783 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2784 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2785 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2786 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2787 --- PASS: TestIsValidCachePath/short_hash (0.00s)2788 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2789 --- PASS: TestIsValidCachePath/empty (0.00s)2790 --- PASS: TestIsValidCachePath/random_path (0.00s)2791 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2792 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2793 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2794=== CONT TestParseSingleRange/none2795=== CONT TestParseSingleRange/end_clamped_to_size2796=== CONT TestParseSingleRange/open-ended2797=== CONT TestParseSingleRange/closed2798=== CONT TestParseSingleRange/malformed_end_before_start2799=== CONT TestParseSingleRange/malformed_both_empty2800=== CONT TestParseSingleRange/malformed_no_dash2801=== CONT TestParseSingleRange/multi-range_ignored2802=== CONT TestParseSingleRange/unknown_unit2803=== CONT TestParseSingleRange/start_past_EOF2804=== CONT TestParseSingleRange/suffix2805=== CONT TestParseSingleRange/single_byte2806=== CONT TestParseSingleRange/suffix_exceeds_size2807=== CONT TestParseSingleRange/start_far_past_EOF2808--- PASS: TestParseSingleRange (0.00s)2809 --- PASS: TestParseSingleRange/none (0.00s)2810 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2811 --- PASS: TestParseSingleRange/open-ended (0.00s)2812 --- PASS: TestParseSingleRange/closed (0.00s)2813 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2814 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2815 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2816 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2817 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2818 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2819 --- PASS: TestParseSingleRange/suffix (0.00s)2820 --- PASS: TestParseSingleRange/single_byte (0.00s)2821 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2822 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2823=== CONT TestServerTLSConfig/no_client_CA2824=== CONT TestServerTLSConfig/not_a_PEM_file2825=== CONT TestServerTLSConfig/missing_CA_file2826--- PASS: TestServerTLSConfig (0.00s)2827 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2828 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2829 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2830=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2831=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected28322026/10/01 09:42:15 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]2833=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2834=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected28352026/10/01 09:42:15 WARN Authentication failed token_preview=eyJhbGciOi...NqEvOXFzPQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]28362026/10/01 09:42:15 OK 20241026095416_initial_model.sql (10.01ms)2837--- PASS: TestService_AuthMiddleware_OIDC (0.49s)2838 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2839 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2840 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2841 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)28422026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)28432026/10/01 09:42:15 OK 20251218171726_add_pins.sql (3ms)28442026-10-01 09:42:15.881 UTC [1498] ERROR: relation "goose_db_version" does not exist at character 3628452026-10-01 09:42:15.881 UTC [1498] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2846=== RUN TestService_RequireScope_OIDC/builder_may_write2847=== PAUSE TestService_RequireScope_OIDC/builder_may_write2848=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2849=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2850=== RUN TestService_RequireScope_OIDC/ops_may_admin2851=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2852=== RUN TestService_RequireScope_OIDC/ops_may_not_write2853=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2854=== RUN TestService_RequireScope_OIDC/reader_may_not_write2855=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2856=== RUN TestService_RequireScope_OIDC/static_token_may_admin2857=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2858=== RUN TestService_RequireScope_OIDC/static_token_may_write2859=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2860=== RUN TestService_RequireScope_OIDC/reader_may_read2861=== PAUSE TestService_RequireScope_OIDC/reader_may_read2862=== RUN TestService_RequireScope_OIDC/writer_implies_read2863=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2864=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2865=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2866=== CONT TestService_RequireScope_OIDC/builder_may_write2867=== CONT TestService_RequireScope_OIDC/static_token_may_admin2868=== CONT TestService_RequireScope_OIDC/ops_may_not_write2869=== CONT TestService_RequireScope_OIDC/reader_may_not_write2870=== CONT TestService_RequireScope_OIDC/writer_implies_read2871=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2872=== CONT TestService_RequireScope_OIDC/ops_may_admin2873=== CONT TestService_RequireScope_OIDC/reader_may_read2874=== CONT TestService_RequireScope_OIDC/builder_may_not_admin28752026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)2876=== CONT TestService_RequireScope_OIDC/static_token_may_write2877--- PASS: TestService_RequireScope_OIDC (0.63s)2878 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2879 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2880 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2881 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2882 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2883 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2884 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2885 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2886 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2887 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)28882026/10/01 09:42:15 OK 20260905000000_add_claims.sql (2.46ms)28892026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (1.87ms)28902026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.56ms)28912026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000028922026/10/01 09:42:15 OK 1_commit_pending_closure.sql (1.82ms)28932026/10/01 09:42:15 OK 2_object_stats_trigger.sql (711.19µs)28942026/10/01 09:42:15 OK 3_commit_push.sql (587.63µs)28952026/10/01 09:42:15 goose: up to current file version: 328962026/10/01 09:42:15 OK 20241026095416_initial_model.sql (8.81ms)28972026/10/01 09:42:15 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)28982026/10/01 09:42:15 OK 20251218171726_add_pins.sql (2.75ms)28992026/10/01 09:42:15 OK 20260628120000_add_object_size_and_stats.sql (3.2ms)29002026/10/01 09:42:15 OK 20260905000000_add_claims.sql (2.15ms)29012026/10/01 09:42:15 OK 20260920000000_drop_claims.sql (1.7ms)29022026/10/01 09:42:15 OK 20260923120000_add_pushes.sql (1.23ms)29032026/10/01 09:42:15 goose: successfully migrated database to version: 2026092312000029042026/10/01 09:42:15 OK 1_commit_pending_closure.sql (1.55ms)29052026/10/01 09:42:15 OK 2_object_stats_trigger.sql (665.99µs)29062026/10/01 09:42:15 OK 3_commit_push.sql (594.37µs)29072026/10/01 09:42:15 goose: up to current file version: 329082026/10/01 09:42:15 INFO Received uploads request method=POST path=/api/pending_closures2909=== NAME TestClientCADerivations2910 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2911 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2912 error: binary cache 's3://bucket59?endpoint=http://localhost:41511®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3802157080/001/store'2913 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12914--- PASS: TestClientCADerivations (0.74s)2915--- PASS: TestObjectStatsTrigger (0.44s)29162026/10/01 09:42:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.873322ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2917--- PASS: TestPresentReportsOnlyClosureRoots (0.43s)29182026/10/01 09:42:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"29192026/10/01 09:42:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2920--- PASS: TestService_NativeMTLS (0.41s)29212026/10/01 09:42:16 WARN readiness check failed error="closed pool"2922--- PASS: TestService_readinessHandler (0.41s)29232026/10/01 09:42:16 INFO Aborted multipart uploads count=0 kept=029242026/10/01 09:42:16 WARN Force mode enabled - objects will be deleted immediately without grace period29252026/10/01 09:42:16 INFO Received cleanup request method=DELETE path=/api/pending_closures29262026/10/01 09:42:16 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=029272026/10/01 09:42:16 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket74/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""29282026/10/01 09:42:16 INFO Aborted multipart uploads count=0 kept=129292026/10/01 09:42:16 INFO Vacuumed table table=pending_closures29302026/10/01 09:42:16 INFO Vacuumed table table=pending_objects29312026/10/01 09:42:16 INFO Vacuumed table table=multipart_uploads29322026/10/01 09:42:16 INFO Received cleanup request method=DELETE path=/api/pending_closures29332026/10/01 09:42:16 INFO Vacuumed table table=closures29342026/10/01 09:42:16 INFO Vacuumed table table=objects29352026/10/01 09:42:16 INFO Aborted multipart uploads count=1 kept=02936--- PASS: TestMultipartCleanup (0.57s)2937--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.45s)29382026/10/01 09:42:16 INFO Received uploads request method=POST path=/api/pending_closures2939=== NAME TestNARDeduplicationMetadataUploadBug2940 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4228807745/001/store/h9n3lgfg8v64cx7y7b85a99m389cj824-file1.txt29412026/10/01 09:42:16 INFO Aborted multipart uploads count=0 kept=029422026/10/01 09:42:16 WARN Force mode enabled - objects will be deleted immediately without grace period29432026/10/01 09:42:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29442026/10/01 09:42:16 WARN Refused reserved pin name=worker-x86_64-linux29452026/10/01 09:42:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux29462026/10/01 09:42:16 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=029472026/10/01 09:42:16 INFO Received create pin request method=POST path=/api/pins/my-app29482026/10/01 09:42:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2949--- PASS: TestCreatePin_ReservedPins (0.71s)29502026/10/01 09:42:16 INFO Vacuumed table table=pending_closures29512026/10/01 09:42:16 INFO Vacuumed table table=pending_objects29522026/10/01 09:42:16 INFO Vacuumed table table=multipart_uploads29532026/10/01 09:42:16 INFO Vacuumed table table=closures29542026/10/01 09:42:16 INFO Vacuumed table table=objects29552026/10/01 09:42:16 INFO Received uploads request method=POST path=/api/pending_closures29562026/10/01 09:42:16 INFO Aborted multipart uploads count=0 kept=029572026/10/01 09:42:16 WARN Force mode enabled - objects will be deleted immediately without grace period29582026/10/01 09:42:16 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=029592026/10/01 09:42:16 INFO Vacuumed table table=pending_closures29602026/10/01 09:42:16 INFO Vacuumed table table=pending_objects29612026/10/01 09:42:16 INFO Vacuumed table table=multipart_uploads29622026/10/01 09:42:16 INFO Vacuumed table table=closures29632026/10/01 09:42:16 INFO Vacuumed table table=objects2964--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2965 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.46s)2966 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.41s)29672026/10/01 09:42:16 INFO Received push request method=POST path=/api/pushes29682026/10/01 09:42:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29692026/10/01 09:42:16 INFO Uploading h9n3lgfg8v64cx7y7b85a99m389cj824-file1.txt (160B)29702026/10/01 09:42:16 WARN Failed to register uploaded object key=h9n3lgfg8v64cx7y7b85a99m389cj824.ls error="server returned 404: 404 page not found\n"29712026/10/01 09:42:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29722026/10/01 09:42:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"29732026/10/01 09:42:16 INFO Signed narinfos id=1 count=129742026/10/01 09:42:16 INFO Uploading 1 narinfos29752026/10/01 09:42:16 INFO Received complete push request method=POST path=/api/pushes/1/complete29762026/10/01 09:42:16 WARN Failed to register uploaded object key=h9n3lgfg8v64cx7y7b85a99m389cj824.narinfo error="server returned 404: 404 page not found\n"29772026/10/01 09:42:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.338034ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29782026/10/01 09:42:16 INFO Upload complete. (55ms)2979=== NAME TestNARDeduplicationMetadataUploadBug2980 metadata_upload_test.go:54: Retrieved narinfo from S3:2981 StorePath: /build/TestNARDeduplicationMetadataUploadBug4228807745/001/store/h9n3lgfg8v64cx7y7b85a99m389cj824-file1.txt2982 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2983 Compression: zstd2984 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2985 NarSize: 1602986 References: 2987 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2988 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2989 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2990 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2991=== NAME TestOrphanedObjectsGC2992 orphaned_objects_gc_test.go:290: GC Test Summary:2993 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2994 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2995 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2996 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2997 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2998--- PASS: TestOrphanedObjectsGC (0.74s)2999=== NAME TestNARDeduplicationMetadataUploadBug3000 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4228807745/001/store/rb1syssyv955m4j4paij38vfq61brj2g-file2.txt30012026/10/01 09:42:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30022026/10/01 09:42:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30032026/10/01 09:42:16 INFO Received push request method=POST path=/api/pushes30042026/10/01 09:42:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)30052026/10/01 09:42:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign30062026/10/01 09:42:16 INFO Signed narinfos id=2 count=130072026/10/01 09:42:16 WARN Failed to register uploaded object key=rb1syssyv955m4j4paij38vfq61brj2g.ls error="server returned 404: 404 page not found\n"30082026/10/01 09:42:16 INFO Uploading 1 narinfos30092026/10/01 09:42:16 INFO Received complete push request method=POST path=/api/pushes/2/complete30102026/10/01 09:42:16 WARN Failed to register uploaded object key=rb1syssyv955m4j4paij38vfq61brj2g.narinfo error="server returned 404: 404 page not found\n"30112026/10/01 09:42:16 INFO Upload complete. (46ms)3012 metadata_upload_test.go:76: Retrieved narinfo from S3:3013 StorePath: /build/TestNARDeduplicationMetadataUploadBug4228807745/001/store/rb1syssyv955m4j4paij38vfq61brj2g-file2.txt3014 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst3015 Compression: zstd3016 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3017 NarSize: 1603018 References: 3019 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf3020 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)3021 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):3022 {"version":1,"root":{"type":"regular","size":44}}3023--- PASS: TestNARDeduplicationMetadataUploadBug (0.66s)3024--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.94s)30252026/10/01 09:42:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.325203ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3026--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)3027 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)3028 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)3029 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.84s)30302026/10/01 09:42:16 WARN Rate limiter enabled after throttle name=s3-test rate=530312026/10/01 09:42:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3032=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3033 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103034 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003035--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (2.92s)3036=== NAME TestOrphanedObjectsGCStressTest3037 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains3038 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion3039 orphaned_objects_gc_test.go:509: Stress test completed successfully:3040 orphaned_objects_gc_test.go:510: - Active objects preserved: 203041 orphaned_objects_gc_test.go:511: - Objects deleted: 2103042 orphaned_objects_gc_test.go:512: - Total GC'd: 2103043--- PASS: TestOrphanedObjectsGCStressTest (1.86s)30442026/10/01 09:42:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=030452026/10/01 09:42:17 INFO Received create pin request method=POST path=/api/pins/myapp30462026/10/01 09:42:17 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1938861288/001/store/pncq4l80gcdrhgj5f2dg4bx2y1bhydwa-pinned-file.txt narinfo_key=pncq4l80gcdrhgj5f2dg4bx2y1bhydwa.narinfo30472026/10/01 09:42:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures30482026/10/01 09:42:17 INFO Garbage collection started30492026/10/01 09:42:17 INFO Aborted multipart uploads count=0 kept=030502026/10/01 09:42:17 WARN Force mode enabled - objects will be deleted immediately without grace period30512026/10/01 09:42:17 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=030522026/10/01 09:42:17 INFO Vacuumed table table=pending_closures30532026/10/01 09:42:17 INFO Vacuumed table table=pending_objects30542026/10/01 09:42:17 INFO Vacuumed table table=multipart_uploads30552026/10/01 09:42:17 INFO Vacuumed table table=closures30562026/10/01 09:42:17 INFO Vacuumed table table=objects30572026/10/01 09:42:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.503710153s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30582026/10/01 09:42:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03059=== NAME TestClientIntegration3060 client_integration_test.go:323: Objects in database after GC:3061 client_integration_test.go:323: Successfully deleted all objects with GC --force3062--- PASS: TestClientIntegration (2.61s)30632026/10/01 09:42:18 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-config30642026/10/01 09:42:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.558042ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30652026/10/01 09:42:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=419.799712ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3066=== NAME TestPinProtectsFromGC3067 client_integration_test.go:840: Pin successfully protected closure from garbage collection3068--- PASS: TestPinProtectsFromGC (4.76s)30692026/10/01 09:42:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=828.894128ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30702026/10/01 09:42:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.533889921s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30712026/10/01 09:42:21 INFO Aborted multipart uploads count=1 kept=030722026/10/01 09:42:21 INFO Received cleanup request method=DELETE path=/api/pending_closures30732026/10/01 09:42:21 INFO Aborted multipart uploads count=1 kept=03074--- PASS: TestPendingCleanupUsesOneCutoff (6.44s)30752026/10/01 09:42:22 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"30762026/10/01 09:42:22 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-config30772026/10/01 09:42:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.342377ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30782026/10/01 09:42:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.614383ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30792026/10/01 09:42:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=770.712586ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30802026/10/01 09:42:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.573655005s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30812026/10/01 09:42:25 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_closures30822026/10/01 09:42:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.996758ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30832026/10/01 09:42:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.100696ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30842026/10/01 09:42:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.285546ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30852026/10/01 09:42:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.630216575s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3086--- PASS: TestClientErrorHandling (0.00s)3087 --- PASS: TestClientErrorHandling/InvalidStorePath (0.34s)3088 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.41s)3089 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.30s)3090PASS30912026-10-01 09:42:28.323 UTC [126] LOG: received smart shutdown request30922026-10-01 09:42:28.329 UTC [126] LOG: background worker "logical replication launcher" (PID 136) exited with exit code 130932026-10-01 09:42:28.338 UTC [131] LOG: shutting down30942026-10-01 09:42:28.339 UTC [131] LOG: checkpoint starting: shutdown immediate30952026-10-01 09:42:30.105 UTC [131] LOG: checkpoint complete: wrote 10592 buffers (64.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.216 s, sync=1.525 s, total=1.767 s; sync files=28648, longest=0.156 s, average=0.001 s; distance=396496 kB, estimate=396496 kB; lsn=0/19A99CE0, redo lsn=0/19A99CE030962026-10-01 09:42:30.175 UTC [126] LOG: database system is shut down3097Running OIDC tests...3098=== RUN TestAudienceForIssuer3099=== PAUSE TestAudienceForIssuer3100=== RUN TestGlobMatch3101=== PAUSE TestGlobMatch3102=== RUN TestValidateToken_ValidToken3103=== PAUSE TestValidateToken_ValidToken3104=== RUN TestValidateToken_WrongAudience3105=== PAUSE TestValidateToken_WrongAudience3106=== RUN TestValidateToken_Expired3107=== PAUSE TestValidateToken_Expired3108=== RUN TestValidateToken_BoundClaimsMismatch3109=== PAUSE TestValidateToken_BoundClaimsMismatch3110=== RUN TestValidateToken_BoundSubjectMismatch3111=== PAUSE TestValidateToken_BoundSubjectMismatch3112=== RUN TestValidateToken_MultipleProviders3113=== PAUSE TestValidateToken_MultipleProviders3114=== RUN TestValidateToken_NoMatchingProvider3115=== PAUSE TestValidateToken_NoMatchingProvider3116=== RUN TestValidateToken_KubernetesServiceAccount3117=== PAUSE TestValidateToken_KubernetesServiceAccount3118=== RUN TestNewValidator_KubernetesRequiresCA3119=== PAUSE TestNewValidator_KubernetesRequiresCA3120=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3121=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3122=== RUN TestPins_ReservedForMatchingRule3123=== PAUSE TestPins_ReservedForMatchingRule3124=== RUN TestPins_TopLevelShorthand3125=== PAUSE TestPins_TopLevelShorthand3126=== RUN TestPins_ConfigValidation3127=== PAUSE TestPins_ConfigValidation3128=== RUN TestScopes_LegacyProviderDefaultsToWrite3129=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3130=== RUN TestScopes_Rules3131=== PAUSE TestScopes_Rules3132=== RUN TestScopes_ConfigValidation3133=== PAUSE TestScopes_ConfigValidation3134=== CONT TestAudienceForIssuer3135=== CONT TestValidateToken_KubernetesServiceAccount3136--- PASS: TestAudienceForIssuer (0.00s)3137=== CONT TestValidateToken_ValidToken3138=== CONT TestValidateToken_BoundClaimsMismatch3139=== CONT TestValidateToken_WrongAudience3140=== CONT TestGlobMatch3141=== RUN TestGlobMatch/foo_foo3142=== PAUSE TestGlobMatch/foo_foo3143=== RUN TestGlobMatch/foo_bar3144=== PAUSE TestGlobMatch/foo_bar3145=== RUN TestGlobMatch/*_3146=== PAUSE TestGlobMatch/*_3147=== RUN TestGlobMatch/*_anything3148=== PAUSE TestGlobMatch/*_anything3149=== CONT TestValidateToken_MultipleProviders3150=== CONT TestValidateToken_NoMatchingProvider3151=== CONT TestValidateToken_Expired3152=== CONT TestValidateToken_BoundSubjectMismatch3153=== CONT TestPins_ConfigValidation3154=== CONT TestScopes_ConfigValidation3155=== CONT TestScopes_Rules3156=== CONT TestScopes_LegacyProviderDefaultsToWrite3157=== CONT TestPins_ReservedForMatchingRule3158=== CONT TestPins_TopLevelShorthand3159=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3160--- PASS: TestPins_ConfigValidation (0.00s)3161=== CONT TestNewValidator_KubernetesRequiresCA3162=== RUN TestGlobMatch/foo*_foo3163=== PAUSE TestGlobMatch/foo*_foo3164--- PASS: TestScopes_ConfigValidation (0.00s)3165=== RUN TestGlobMatch/foo*_foobar3166=== PAUSE TestGlobMatch/foo*_foobar3167=== RUN TestGlobMatch/foo*_bar3168=== PAUSE TestGlobMatch/foo*_bar3169=== RUN TestGlobMatch/*bar_bar3170=== PAUSE TestGlobMatch/*bar_bar3171=== RUN TestGlobMatch/*bar_foobar3172=== PAUSE TestGlobMatch/*bar_foobar3173=== RUN TestGlobMatch/*bar_foo3174=== PAUSE TestGlobMatch/*bar_foo3175=== RUN TestGlobMatch/foo*bar_foobar3176=== PAUSE TestGlobMatch/foo*bar_foobar3177=== RUN TestGlobMatch/foo*bar_foo123bar3178=== PAUSE TestGlobMatch/foo*bar_foo123bar3179=== RUN TestGlobMatch/foo*bar_foobarbaz3180=== PAUSE TestGlobMatch/foo*bar_foobarbaz3181=== RUN TestGlobMatch/*/*_foo/bar3182=== PAUSE TestGlobMatch/*/*_foo/bar3183=== RUN TestGlobMatch/*/*_foo3184=== PAUSE TestGlobMatch/*/*_foo3185=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3186=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3187=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03188=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03189=== RUN TestGlobMatch/refs/*/main_refs/heads/main3190=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3191=== RUN TestGlobMatch/fo?_foo3192=== PAUSE TestGlobMatch/fo?_foo3193=== RUN TestGlobMatch/fo?_fo3194=== PAUSE TestGlobMatch/fo?_fo3195=== RUN TestGlobMatch/fo?_fooo3196=== PAUSE TestGlobMatch/fo?_fooo3197=== RUN TestGlobMatch/?oo_foo3198=== PAUSE TestGlobMatch/?oo_foo3199=== RUN TestGlobMatch/?oo_boo3200=== PAUSE TestGlobMatch/?oo_boo3201=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3202=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3203=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3204=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3205=== CONT TestGlobMatch/foo_foo3206=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03207=== CONT TestGlobMatch/foo*bar_foo123bar3208=== CONT TestGlobMatch/foo*_foobar3209=== CONT TestGlobMatch/foo*_foo3210=== CONT TestGlobMatch/*_anything3211=== CONT TestGlobMatch/*_3212=== CONT TestGlobMatch/foo_bar3213=== CONT TestGlobMatch/foo*bar_foobarbaz3214=== CONT TestGlobMatch/?oo_foo3215=== CONT TestGlobMatch/*/*_foo3216=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3217=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3218=== CONT TestGlobMatch/*/*_foo/bar3219=== CONT TestGlobMatch/fo?_foo3220=== CONT TestGlobMatch/refs/*/main_refs/heads/main3221=== CONT TestGlobMatch/?oo_boo3222=== CONT TestGlobMatch/foo*bar_foobar3223=== CONT TestGlobMatch/*bar_foo3224=== CONT TestGlobMatch/*bar_foobar3225=== CONT TestGlobMatch/*bar_bar3226=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3227=== CONT TestGlobMatch/foo*_bar3228=== CONT TestGlobMatch/fo?_fooo3229=== CONT TestGlobMatch/fo?_fo3230--- PASS: TestGlobMatch (0.00s)3231 --- PASS: TestGlobMatch/foo_foo (0.00s)3232 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3233 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3234 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3235 --- PASS: TestGlobMatch/foo*_foo (0.00s)3236 --- PASS: TestGlobMatch/*_anything (0.00s)3237 --- PASS: TestGlobMatch/*_ (0.00s)3238 --- PASS: TestGlobMatch/foo_bar (0.00s)3239 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3240 --- PASS: TestGlobMatch/?oo_foo (0.00s)3241 --- PASS: TestGlobMatch/*/*_foo (0.00s)3242 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3243 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3244 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3245 --- PASS: TestGlobMatch/fo?_foo (0.00s)3246 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3247 --- PASS: TestGlobMatch/?oo_boo (0.00s)3248 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3249 --- PASS: TestGlobMatch/*bar_foo (0.00s)3250 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3251 --- PASS: TestGlobMatch/*bar_bar (0.00s)3252 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3253 --- PASS: TestGlobMatch/foo*_bar (0.00s)3254 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3255 --- PASS: TestGlobMatch/fo?_fo (0.00s)32562026/10/01 09:42:31 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3670332572026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43613/oidc3258--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)3259--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)32602026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38467/oidc3261--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)32622026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45011/oidc3263--- PASS: TestValidateToken_WrongAudience (0.14s)32642026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45059/oidc32652026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43965/oidc32662026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41421/oidc3267--- PASS: TestValidateToken_BoundSubjectMismatch (0.15s)3268--- PASS: TestValidateToken_Expired (0.15s)32692026/10/01 09:42:31 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35961/oidc32702026/10/01 09:42:31 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:32959/oidc3271--- PASS: TestPins_ReservedForMatchingRule (0.15s)3272--- PASS: TestValidateToken_MultipleProviders (0.16s)32732026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34061/oidc3274--- PASS: TestScopes_Rules (0.17s)32752026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45507/oidc3276--- PASS: TestValidateToken_ValidToken (0.18s)32772026/10/01 09:42:31 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39281/oidc3278--- PASS: TestValidateToken_NoMatchingProvider (0.20s)32792026/10/01 09:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38457/oidc3280--- PASS: TestPins_TopLevelShorthand (0.27s)32812026/10/01 09:42:32 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233282--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.49s)32832026/10/01 09:42:32 http: TLS handshake error from 127.0.0.1:46688: remote error: tls: bad certificate3284--- PASS: TestNewValidator_KubernetesRequiresCA (0.55s)3285PASS3286Running hook tests...3287=== RUN TestSendPathsEmpty3288=== PAUSE TestSendPathsEmpty3289=== RUN TestQueueEnqueueAndFetch3290=== PAUSE TestQueueEnqueueAndFetch3291=== RUN TestQueueDeduplication3292=== PAUSE TestQueueDeduplication3293=== RUN TestQueueRemove3294=== PAUSE TestQueueRemove3295=== RUN TestQueueFetchBatchLimit3296=== PAUSE TestQueueFetchBatchLimit3297=== RUN TestQueueRetryMovesToBack3298=== PAUSE TestQueueRetryMovesToBack3299=== RUN TestQueueFetchRemoveLifecycle3300=== PAUSE TestQueueFetchRemoveLifecycle3301=== RUN TestQueueConcurrentWriters3302=== PAUSE TestQueueConcurrentWriters3303=== RUN TestQueueRemoveLargeClosure3304=== PAUSE TestQueueRemoveLargeClosure3305=== RUN TestServerClientIntegration3306=== PAUSE TestServerClientIntegration3307=== RUN TestServerQueueError3308=== PAUSE TestServerQueueError3309=== RUN TestGetListenerSocketActivation3310 server_test.go:210: === RUN TestGetListenerSocketActivation3311 --- PASS: TestGetListenerSocketActivation (0.00s)3312 PASS3313 3314--- PASS: TestGetListenerSocketActivation (0.01s)3315=== RUN TestDrainIsolatesPoisonPath3316=== PAUSE TestDrainIsolatesPoisonPath3317=== RUN TestRunNotBlockedByPoisonHead3318=== PAUSE TestRunNotBlockedByPoisonHead3319=== RUN TestDrainGivesUpWhenServerDown3320=== PAUSE TestDrainGivesUpWhenServerDown3321=== RUN TestFailedPathPrunedByLaterClosure3322=== PAUSE TestFailedPathPrunedByLaterClosure3323=== RUN TestWorkerUploadsAndRemoves3324=== PAUSE TestWorkerUploadsAndRemoves3325=== RUN TestWorkerSkipsGCdPaths3326=== PAUSE TestWorkerSkipsGCdPaths3327=== RUN TestWorkerPrunesClosureDeps3328=== PAUSE TestWorkerPrunesClosureDeps3329=== RUN TestDrainTimeout3330=== PAUSE TestDrainTimeout3331=== CONT TestSendPathsEmpty3332=== CONT TestDrainIsolatesPoisonPath3333--- PASS: TestSendPathsEmpty (0.00s)3334=== CONT TestServerQueueError3335=== CONT TestServerClientIntegration3336=== CONT TestQueueRemoveLargeClosure3337=== CONT TestQueueConcurrentWriters3338=== CONT TestQueueFetchRemoveLifecycle33392026/10/01 09:42:32 ERROR Failed to queue paths error="permission denied" count=13340=== CONT TestQueueRetryMovesToBack3341=== CONT TestQueueFetchBatchLimit3342=== CONT TestQueueRemove3343--- PASS: TestServerQueueError (0.00s)3344=== CONT TestWorkerUploadsAndRemoves3345=== CONT TestQueueDeduplication3346=== CONT TestQueueEnqueueAndFetch3347=== CONT TestDrainTimeout3348--- PASS: TestServerClientIntegration (0.00s)3349=== CONT TestWorkerSkipsGCdPaths3350=== CONT TestWorkerPrunesClosureDeps3351=== CONT TestDrainGivesUpWhenServerDown3352=== CONT TestFailedPathPrunedByLaterClosure3353=== CONT TestRunNotBlockedByPoisonHead33542026/10/01 09:42:32 INFO Uploading batch count=433552026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=433562026/10/01 09:42:32 INFO Uploading batch count=133572026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=133582026/10/01 09:42:32 INFO Uploading batch count=233592026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=233602026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2175022043/002/a33612026/10/01 09:42:32 INFO Uploading batch count=233622026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath781314456/002/bbb33632026/10/01 09:42:32 INFO Upload queue status pending=23364--- PASS: TestQueueDeduplication (0.01s)33652026/10/01 09:42:32 INFO Upload queue status pending=23366--- PASS: TestQueueFetchBatchLimit (0.01s)33672026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2175022043/002/b3368--- PASS: TestQueueEnqueueAndFetch (0.01s)33692026/10/01 09:42:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1117440850/002/nonexistent33702026/10/01 09:42:32 INFO Uploading batch count=133712026/10/01 09:42:32 INFO Uploading batch count=133722026/10/01 09:42:32 INFO Upload queue status pending=333732026/10/01 09:42:32 INFO Uploading batch count=133742026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=13375--- PASS: TestQueueFetchRemoveLifecycle (0.01s)33762026/10/01 09:42:32 INFO Uploading batch count=233772026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=233782026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2175022043/002/c33792026/10/01 09:42:32 INFO Uploading batch count=13380--- PASS: TestQueueRemove (0.01s)33812026/10/01 09:42:32 INFO Upload queue status pending=233822026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2175022043/002/d33832026/10/01 09:42:32 INFO Uploading batch count=233842026/10/01 09:42:32 INFO Uploading batch count=133852026/10/01 09:42:32 INFO Uploading batch count=13386--- PASS: TestQueueRetryMovesToBack (0.02s)33872026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=133882026/10/01 09:42:32 INFO Uploading batch count=233892026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=233902026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2175022043/002/e33912026/10/01 09:42:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2175022043/002/f33922026/10/01 09:42:32 INFO Uploading batch count=133932026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=133942026/10/01 09:42:32 ERROR Drain finished with paths left in queue remaining=1033952026/10/01 09:42:32 INFO Uploading batch count=133962026/10/01 09:42:32 ERROR Upload failed error="upload failed" count=13397--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)33982026/10/01 09:42:32 ERROR Drain finished with paths left in queue remaining=13399--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3400--- PASS: TestDrainIsolatesPoisonPath (0.02s)3401--- PASS: TestWorkerSkipsGCdPaths (0.03s)3402--- PASS: TestWorkerPrunesClosureDeps (0.03s)3403--- PASS: TestWorkerUploadsAndRemoves (0.03s)3404--- PASS: TestQueueRemoveLargeClosure (0.14s)34052026/10/01 09:42:32 ERROR Upload failed error="context deadline exceeded" count=234062026/10/01 09:42:32 ERROR Drain finished with paths left in queue remaining=43407--- PASS: TestDrainTimeout (0.21s)3408--- PASS: TestQueueConcurrentWriters (0.22s)34092026/10/01 09:42:33 INFO Uploading batch count=134102026/10/01 09:42:33 INFO Uploading batch count=134112026/10/01 09:42:33 INFO Uploading batch count=134122026/10/01 09:42:33 ERROR Upload failed error="upload failed" count=134132026/10/01 09:42:33 INFO Uploading batch count=134142026/10/01 09:42:33 ERROR Upload failed error="upload failed" count=134152026/10/01 09:42:33 INFO Uploading batch count=134162026/10/01 09:42:33 ERROR Upload failed error="upload failed" count=134172026/10/01 09:42:33 INFO Uploading batch count=134182026/10/01 09:42:33 ERROR Upload failed error="upload failed" count=134192026/10/01 09:42:33 ERROR Drain finished with paths left in queue remaining=13420--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3421PASS