niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #202
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathCaseHackMatchesNix14--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)15=== RUN TestDumpPathCaseHackCollision16--- PASS: TestDumpPathCaseHackCollision (0.00s)17=== RUN TestDumpPathMatchesNix18=== PAUSE TestDumpPathMatchesNix19=== RUN TestDumpPathSingleFile20=== PAUSE TestDumpPathSingleFile21=== RUN TestDumpPathWriterError22=== PAUSE TestDumpPathWriterError23=== RUN TestEncodeNixBase3224=== PAUSE TestEncodeNixBase3225=== RUN TestEncodeNixBase32WithRealHash26=== PAUSE TestEncodeNixBase32WithRealHash27=== RUN TestConvertHashToNix3228=== PAUSE TestConvertHashToNix3229=== RUN TestGetStorePathHash30=== PAUSE TestGetStorePathHash31=== RUN TestPathInfoHashCompatibility32=== PAUSE TestPathInfoHashCompatibility33=== RUN TestParsePathInfoJSON34=== PAUSE TestParsePathInfoJSON35=== RUN TestParsePathInfoJSONMultiplePaths36=== PAUSE TestParsePathInfoJSONMultiplePaths37=== RUN TestPathInfoCACompatibility38=== PAUSE TestPathInfoCACompatibility39=== RUN TestRateLimiterFeedback40=== PAUSE TestRateLimiterFeedback41=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== RUN TestResolveStorePath44=== PAUSE TestResolveStorePath45=== RUN TestDoWithRetry_BodyReplayedViaGetBody46=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody47=== RUN TestShellSplit48=== PAUSE TestShellSplit49=== RUN TestShellSplitErrors50=== PAUSE TestShellSplitErrors51=== RUN TestStreamPushReportsEveryPath52=== PAUSE TestStreamPushReportsEveryPath53=== RUN TestStreamPushBatchesUnderLoad54=== PAUSE TestStreamPushBatchesUnderLoad55=== RUN TestStreamPushIsolatesFailures56=== PAUSE TestStreamPushIsolatesFailures57=== RUN TestStreamPushGivesUpOnDeadServer58=== PAUSE TestStreamPushGivesUpOnDeadServer59=== RUN TestSetClientTLS60=== PAUSE TestSetClientTLS61=== RUN TestSetClientTLSDoesNotMutateDefaultTransport62=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport63=== RUN TestSetClientTLSErrors64=== PAUSE TestSetClientTLSErrors65=== RUN TestStaticToken66=== PAUSE TestStaticToken67=== RUN TestFileTokenReadsAndCaches68=== PAUSE TestFileTokenReadsAndCaches69=== RUN TestFileTokenMissing70=== PAUSE TestFileTokenMissing71=== RUN TestFileTokenEmpty72=== PAUSE TestFileTokenEmpty73=== RUN TestScriptTokenNoExpiryRerunsEveryCall74=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall75=== RUN TestScriptTokenCachesUntilRefresh76=== PAUSE TestScriptTokenCachesUntilRefresh77=== RUN TestScriptTokenEmptyToken78=== PAUSE TestScriptTokenEmptyToken79=== RUN TestScriptTokenBadJSON80=== PAUSE TestScriptTokenBadJSON81=== RUN TestScriptTokenScriptFails82=== PAUSE TestScriptTokenScriptFails83=== RUN TestScriptTokenEmptyCommand84=== PAUSE TestScriptTokenEmptyCommand85=== CONT TestDoServerRequestAttachesToken86=== CONT TestFileTokenEmpty87=== CONT TestScriptTokenEmptyToken88=== CONT TestScriptTokenNoExpiryRerunsEveryCall89=== CONT TestFileTokenMissing90=== CONT TestFileTokenReadsAndCaches91--- PASS: TestFileTokenMissing (0.00s)92=== CONT TestPathInfoCACompatibility93=== CONT TestStaticToken94=== CONT TestScriptTokenBadJSON95=== CONT TestSetClientTLSDoesNotMutateDefaultTransport96=== CONT TestScriptTokenScriptFails97=== CONT TestSetClientTLS98=== CONT TestShellSplit99=== CONT TestShellSplitErrors100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestStreamPushGivesUpOnDeadServer102=== CONT TestResolveStorePath103=== CONT TestStreamPushIsolatesFailures104=== CONT TestStreamPushBatchesUnderLoad105=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess106=== CONT TestStreamPushReportsEveryPath107=== CONT TestScriptTokenCachesUntilRefresh108=== CONT TestEncodeNixBase32109=== CONT TestRateLimiterFeedback110=== RUN TestPathInfoCACompatibility/null_ca_field111=== CONT TestSetClientTLSErrors112--- PASS: TestFileTokenEmpty (0.00s)113=== CONT TestParsePathInfoJSONMultiplePaths114=== CONT TestParsePathInfoJSON115=== RUN TestParsePathInfoJSON/Nix_format116=== RUN TestEncodeNixBase32/test_string_hash117=== CONT TestGetStorePathHash118=== RUN TestGetStorePathHash/valid_store_path119=== PAUSE TestGetStorePathHash/valid_store_path120=== RUN TestGetStorePathHash/basename_without_hyphen_should_error121=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error122=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error123=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error124=== PAUSE TestParsePathInfoJSON/Nix_format125=== RUN TestParsePathInfoJSON/Lix_format126=== PAUSE TestParsePathInfoJSON/Lix_format127=== CONT TestConvertHashToNix321282026/09/15 10:24:36 WARN Rate limiter enabled after throttle name=server-test rate=5129=== RUN TestRateLimiterFeedback/429_enables_limiter1302026/09/15 10:24:36 ERROR Upload failed error="bad path" count=3131=== PAUSE TestEncodeNixBase32/test_string_hash1322026/09/15 10:24:36 ERROR Upload failed error="connection refused" count=20133=== RUN TestParsePathInfoJSON/empty_input134--- PASS: TestStaticToken (0.00s)1352026/09/15 10:24:36 ERROR Server seems unavailable, giving up on batch untried=17136--- PASS: TestFileTokenReadsAndCaches (0.00s)137=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== CONT TestPathInfoHashCompatibility139=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error140=== PAUSE TestRateLimiterFeedback/429_enables_limiter141=== PAUSE TestPathInfoCACompatibility/null_ca_field142--- PASS: TestShellSplit (0.00s)143--- PASS: TestShellSplitErrors (0.00s)144--- PASS: TestResolveStorePath (0.00s)145--- PASS: TestScriptTokenScriptFails (0.00s)146=== CONT TestEncodeNixBase32WithRealHash147--- PASS: TestEncodeNixBase32WithRealHash (0.00s)148=== CONT TestDumpPathWriterError149=== RUN TestEncodeNixBase32/empty_input150=== PAUSE TestEncodeNixBase32/empty_input151=== RUN TestRateLimiterFeedback/503_enables_limiter152=== PAUSE TestRateLimiterFeedback/503_enables_limiter153=== CONT TestDumpPathSingleFile154=== RUN TestConvertHashToNix32/SRI_format_to_Nix32155=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32156=== CONT TestFilterOversizedClosures157=== RUN TestFilterOversizedClosures/no_limit_keeps_everything158=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestConvertHashToNix32/already_Nix32_format161=== CONT TestUploadMultipart_SupersededByPeer162=== RUN TestUploadMultipart_SupersededByPeer/exists163=== PAUSE TestUploadMultipart_SupersededByPeer/exists164=== CONT TestPartSizeForNAR165=== RUN TestPartSizeForNAR/zero_stays_at_minimum166=== RUN TestPathInfoCACompatibility/old_string_format_-_text167=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter168--- PASS: TestScriptTokenBadJSON (0.00s)169--- PASS: TestStreamPushReportsEveryPath (0.00s)170=== CONT TestDumpPathMatchesNix171=== PAUSE TestParsePathInfoJSON/empty_input172=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error175=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped176=== RUN TestConvertHashToNix32/invalid_format177=== RUN TestUploadMultipart_SupersededByPeer/missing178--- PASS: TestStreamPushIsolatesFailures (0.00s)179--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)180--- PASS: TestScriptTokenEmptyToken (0.01s)181=== CONT TestEncodeNixBase32/test_string_hash182=== CONT TestEncodeNixBase32/empty_input183=== CONT TestCaseHackSuffix184--- PASS: TestEncodeNixBase32 (0.00s)185 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)186 --- PASS: TestEncodeNixBase32/empty_input (0.00s)187=== CONT TestGetStorePathHash/valid_store_path188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text189=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter190=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error191=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum192=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter193=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive194=== CONT TestScriptTokenEmptyCommand195--- PASS: TestScriptTokenEmptyCommand (0.00s)196=== CONT TestGetStorePathHash/basename_without_hyphen_should_error197--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)198=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error199=== RUN TestParsePathInfoJSON/whitespace_only200=== PAUSE TestParsePathInfoJSON/whitespace_only201=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter202=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive203--- PASS: TestGetStorePathHash (0.00s)204 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)205 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)206 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)207 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)208=== CONT TestRateLimiterFeedback/429_enables_limiter209=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter210=== CONT TestRateLimiterFeedback/503_enables_limiter211=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestUploadMultipart_SupersededByPeer/missing214=== PAUSE TestConvertHashToNix32/invalid_format215=== CONT TestUploadMultipart_SupersededByPeer/exists2162026/09/15 10:24:36 WARN Rate limiter enabled after throttle name=server-test rate=5217=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2182026/09/15 10:24:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45897219=== RUN TestSetClientTLSErrors/missing_cert_file220--- PASS: TestDoServerRequestAttachesToken (0.01s)221=== CONT TestConvertHashToNix32/SRI_format_to_Nix322222026/09/15 10:24:36 WARN Rate limiter enabled after throttle name=server-test rate=5223--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)2242026/09/15 10:24:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:46211225=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2262026/09/15 10:24:36 WARN Rate limiter backed off name=server-test rate=5227=== CONT TestConvertHashToNix32/invalid_format2282026/09/15 10:24:36 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45897229=== RUN TestParsePathInfoJSON/invalid_JSON230=== RUN TestPathInfoCACompatibility/new_structured_format_-_text231=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths232=== RUN TestPartSizeForNAR/small_stays_at_minimum233=== RUN TestFilterOversizedClosures/all_closures_skipped234=== CONT TestUploadMultipart_SupersededByPeer/missing235=== PAUSE TestSetClientTLSErrors/missing_cert_file236=== CONT TestConvertHashToNix32/already_Nix32_format237=== RUN TestSetClientTLS/rejects_connection_without_client_cert238=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon2392026/09/15 10:24:36 WARN Rate limiter enabled after throttle name=server-test rate=5240=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text2412026/09/15 10:24:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44199242=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method243=== PAUSE TestPartSizeForNAR/small_stays_at_minimum244=== PAUSE TestParsePathInfoJSON/invalid_JSON245=== RUN TestSetClientTLSErrors/missing_key_file246=== PAUSE TestFilterOversizedClosures/all_closures_skipped247--- PASS: TestConvertHashToNix32 (0.01s)248 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)249 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)250 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)251=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2522026/09/15 10:24:36 WARN Rate limiter backed off name=server-test rate=5253=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths254=== CONT TestParsePathInfoJSON/Lix_format255=== CONT TestFilterOversizedClosures/no_limit_keeps_everything256=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert257=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA258=== CONT TestFilterOversizedClosures/all_closures_skipped259=== CONT TestParsePathInfoJSON/Nix_format260=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon261=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum262=== CONT TestParsePathInfoJSON/invalid_JSON263=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2652026/09/15 10:24:36 WARN Rate limiter backed off name=server-test rate=5266--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)267 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)268 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)269=== CONT TestParsePathInfoJSON/whitespace_only2702026/09/15 10:24:36 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=2000271--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)2722026/09/15 10:24:36 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50273=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA274=== RUN TestSetClientTLS/preserves_debug_logging_transport275=== CONT TestParsePathInfoJSON/empty_input276=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI277=== CONT TestPathInfoCACompatibility/null_ca_field278=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI279=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method280=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum281=== CONT TestPathInfoCACompatibility/new_structured_format_-_text282=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive283=== CONT TestPathInfoCACompatibility/old_string_format_-_text284=== PAUSE TestSetClientTLSErrors/missing_key_file285=== RUN TestSetClientTLSErrors/missing_ca_file286--- PASS: TestFilterOversizedClosures (0.01s)287 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)288 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)289 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)290=== PAUSE TestSetClientTLS/preserves_debug_logging_transport291=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512292=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512293=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts294=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts295=== RUN TestPartSizeForNAR/1_TiB296=== PAUSE TestPartSizeForNAR/1_TiB297=== RUN TestPartSizeForNAR/5_TiB_S3_max_object298=== PAUSE TestSetClientTLSErrors/missing_ca_file299=== RUN TestSetClientTLSErrors/invalid_ca_file300--- PASS: TestRateLimiterFeedback (0.01s)301 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)302 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)303 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)304 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)305--- PASS: TestParsePathInfoJSON (0.02s)306 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)307 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)308 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)309 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)310 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)311--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313=== CONT TestSetClientTLS/preserves_debug_logging_transport314=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA315=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)316=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512317=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI318=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon319=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object320=== PAUSE TestSetClientTLSErrors/invalid_ca_file321=== CONT TestSetClientTLSErrors/missing_cert_file322--- PASS: TestPathInfoCACompatibility (0.02s)323 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)324 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)325 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)326 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)327 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)328=== CONT TestSetClientTLSErrors/invalid_ca_file329=== RUN TestPartSizeForNAR/capped_at_5_GiB330=== PAUSE TestPartSizeForNAR/capped_at_5_GiB331=== CONT TestSetClientTLSErrors/missing_ca_file332=== CONT TestSetClientTLSErrors/missing_key_file333--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)334 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)335 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)336=== CONT TestPartSizeForNAR/zero_stays_at_minimum337=== CONT TestPartSizeForNAR/capped_at_5_GiB338=== CONT TestPartSizeForNAR/5_TiB_S3_max_object339=== CONT TestPartSizeForNAR/1_TiB340=== CONT TestPartSizeForNAR/small_stays_at_minimum341=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts342=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum343--- PASS: TestPathInfoHashCompatibility (0.02s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)348--- PASS: TestPartSizeForNAR (0.02s)349 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)350 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)351 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)352 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)353 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)354 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)355 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)356--- PASS: TestSetClientTLSErrors (0.02s)357 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)358 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)359 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)360 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3612026/09/15 10:24:36 http: TLS handshake error from 127.0.0.1:51566: remote error: tls: bad certificate362--- PASS: TestSetClientTLS (0.02s)363 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)364 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)365 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)366--- PASS: TestDumpPathSingleFile (0.03s)367--- PASS: TestCaseHackSuffix (0.03s)368--- PASS: TestDumpPathWriterError (0.05s)369--- PASS: TestDumpPathMatchesNix (0.09s)370--- PASS: TestStreamPushBatchesUnderLoad (0.10s)371--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)372PASS373Running server tests...374The files belonging to this database system will be owned by user "nixbld".375This user must also own the server process.376377The database cluster will be initialized with locale "C".378The default database encoding has accordingly been set to "SQL_ASCII".379The default text search configuration will be set to "english".380381Data page checksums are enabled.382383creating directory /build/postgres3980603217/data ... ok384creating subdirectories ... ok385selecting dynamic shared memory implementation ... posix386selecting default "max_connections" ... 100387selecting default "shared_buffers" ... 128MB388selecting default time zone ... UTC389creating configuration files ... ok390running bootstrap script ... ok391performing post-bootstrap initialization ... ok392syncing data to disk ... ok393394initdb: warning: enabling "trust" authentication for local connections395initdb: 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.396397Success. You can now start the database server using:398399 pg_ctl -D /build/postgres3980603217/data -l logfile start400401/build/postgres3980603217:5432 - no response4022026-09-15 10:24:38.443 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4032026-09-15 10:24:38.443 UTC [129] LOG: listening on Unix socket "/build/postgres3980603217/.s.PGSQL.5432"4042026-09-15 10:24:38.448 UTC [136] LOG: database system was shut down at 2026-09-15 10:24:38 UTC4052026-09-15 10:24:38.452 UTC [129] LOG: database system is ready to accept connections406/build/postgres3980603217:5432 - accepting connections407=== RUN TestService_AuthMiddleware408=== PAUSE TestService_AuthMiddleware409=== RUN TestService_AuthMiddleware_MTLSProxyHeader410=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader411=== RUN TestService_AuthMiddleware_MTLSBoundSubjects412=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects413=== RUN TestService_ReadAuthMiddleware414=== PAUSE TestService_ReadAuthMiddleware415=== RUN TestService_AuthMiddleware_OIDC416=== PAUSE TestService_AuthMiddleware_OIDC417=== RUN TestService_RequireScope_OIDC418=== PAUSE TestService_RequireScope_OIDC419=== RUN TestService_ReadScope_PublicByDefault420=== PAUSE TestService_ReadScope_PublicByDefault421=== RUN TestCacheConfigHandler422=== PAUSE TestCacheConfigHandler423=== RUN TestCacheStatsHandler424=== PAUSE TestCacheStatsHandler425=== RUN TestClaim_BuildWaitComplete426=== PAUSE TestClaim_BuildWaitComplete427=== RUN TestClaim_GCMarkedOutputCountsAsAbsent428=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent429=== RUN TestClaim_TooManyStreams430=== PAUSE TestClaim_TooManyStreams431=== RUN TestClaim_HolderDisconnectKeepsClaim432=== PAUSE TestClaim_HolderDisconnectKeepsClaim433=== RUN TestClaim_FailWakesWaitersButIsNotRemembered434=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered435=== RUN TestClaim_FailWithoutKindReleases436=== PAUSE TestClaim_FailWithoutKindReleases437=== RUN TestClaim_StaleHeartbeatStolen438=== PAUSE TestClaim_StaleHeartbeatStolen439=== RUN TestClaim_TwoInstances440=== PAUSE TestClaim_TwoInstances441=== RUN TestClaim_InputsTouched442=== PAUSE TestClaim_InputsTouched443=== RUN TestClaim_StreamsThroughServer444=== PAUSE TestClaim_StreamsThroughServer445=== RUN TestClientCADerivations446=== PAUSE TestClientCADerivations447=== RUN TestClientErrorHandling448=== PAUSE TestClientErrorHandling449=== RUN TestClientIntegration450=== PAUSE TestClientIntegration451=== RUN TestClientMultipleUploads452=== PAUSE TestClientMultipleUploads453=== RUN TestClientWithDependencies454=== PAUSE TestClientWithDependencies455=== RUN TestPinProtectsFromGC456=== PAUSE TestPinProtectsFromGC457=== RUN TestResolveDBConnectionString458=== PAUSE TestResolveDBConnectionString459=== RUN TestGCAdvisoryLockBlocksConcurrentRun4602026-09-15 10:24:38.838 UTC [539] ERROR: relation "goose_db_version" does not exist at character 364612026-09-15 10:24:38.838 UTC [539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4622026/09/15 10:24:38 OK 20241026095416_initial_model.sql (10.28ms)4632026/09/15 10:24:38 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)4642026/09/15 10:24:38 OK 20251218171726_add_pins.sql (2.93ms)4652026/09/15 10:24:38 OK 20260628120000_add_object_size_and_stats.sql (2.92ms)4662026/09/15 10:24:38 OK 20260905000000_add_claims.sql (3.29ms)4672026/09/15 10:24:38 goose: successfully migrated database to version: 202609050000004682026/09/15 10:24:38 OK 1_commit_pending_closure.sql (1.67ms)4692026/09/15 10:24:38 OK 2_object_stats_trigger.sql (768.55µs)4702026/09/15 10:24:38 goose: up to current file version: 2471--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)472=== RUN TestGCBugBareHashReferences473=== PAUSE TestGCBugBareHashReferences474=== RUN TestGCMetrics475=== PAUSE TestGCMetrics476=== RUN TestGCTaskStore_StartNew477=== PAUSE TestGCTaskStore_StartNew478=== RUN TestGCTaskStore_DeduplicateSameParams479=== PAUSE TestGCTaskStore_DeduplicateSameParams480=== RUN TestGCTaskStore_ConflictDifferentParams481=== PAUSE TestGCTaskStore_ConflictDifferentParams482=== RUN TestGCTaskStore_GetEmpty483=== PAUSE TestGCTaskStore_GetEmpty484=== RUN TestGCTaskStore_GetReturnsLatest485=== PAUSE TestGCTaskStore_GetReturnsLatest486=== RUN TestGCTaskStore_CompletedAllowsNewTask487=== PAUSE TestGCTaskStore_CompletedAllowsNewTask488=== RUN TestGCTaskStore_PhaseUpdates489=== PAUSE TestGCTaskStore_PhaseUpdates490=== RUN TestGCTaskStore_Fail491=== PAUSE TestGCTaskStore_Fail492=== RUN TestGracefulShutdownDrainsInflight493=== PAUSE TestGracefulShutdownDrainsInflight494=== RUN TestService_healthCheckHandler495=== PAUSE TestService_healthCheckHandler496=== RUN TestService_readinessHandler497=== PAUSE TestService_readinessHandler498=== RUN TestGenerateLandingPage499=== PAUSE TestGenerateLandingPage500=== RUN TestCacheConfigHandlerMaxNarSize501=== PAUSE TestCacheConfigHandlerMaxNarSize502=== RUN TestCreatePendingClosureRejectsOversizedNAR503=== PAUSE TestCreatePendingClosureRejectsOversizedNAR504=== RUN TestNARDeduplicationMetadataUploadBug505=== PAUSE TestNARDeduplicationMetadataUploadBug506=== RUN TestMetricsInventory507=== PAUSE TestMetricsInventory508=== RUN TestService_NativeMTLS509=== PAUSE TestService_NativeMTLS510=== RUN TestServerTLSConfig511=== PAUSE TestServerTLSConfig512=== RUN TestMultipartCleanup513=== PAUSE TestMultipartCleanup514=== RUN TestObjectStatsTrigger515=== PAUSE TestObjectStatsTrigger516=== RUN TestOrphanedObjectsGC517=== PAUSE TestOrphanedObjectsGC518=== RUN TestOrphanedObjectsGCStressTest519=== PAUSE TestOrphanedObjectsGCStressTest520=== RUN TestResurrectedObjectNotDeleted521=== PAUSE TestResurrectedObjectNotDeleted522=== RUN TestParseSingleRange523=== PAUSE TestParseSingleRange524=== RUN TestIsValidCachePath525=== PAUSE TestIsValidCachePath526=== RUN TestReadProxyNarinfo527=== PAUSE TestReadProxyNarinfo528=== RUN TestReadProxyNarinfoAlreadyDecompressed529=== PAUSE TestReadProxyNarinfoAlreadyDecompressed530=== RUN TestReadProxyNarStreaming531=== PAUSE TestReadProxyNarStreaming532=== RUN TestReadProxy404533=== PAUSE TestReadProxy404534=== RUN TestReadProxyInvalidPath535=== PAUSE TestReadProxyInvalidPath536=== RUN TestReadProxyHead537=== PAUSE TestReadProxyHead538=== RUN TestReadProxyConditionalGet539=== PAUSE TestReadProxyConditionalGet540=== RUN TestReadProxyRootRedirectsToIndexHTML541=== PAUSE TestReadProxyRootRedirectsToIndexHTML542=== RUN TestReadProxyDisabled543=== PAUSE TestReadProxyDisabled544=== RUN TestReadRedirectNar545=== PAUSE TestReadRedirectNar546=== RUN TestReadRedirectKeepsNarinfoProxied547=== PAUSE TestReadRedirectKeepsNarinfoProxied548=== RUN TestReadProxyRangeRequest549=== PAUSE TestReadProxyRangeRequest550=== RUN TestReadRedirectUsesPublicS3URL551=== PAUSE TestReadRedirectUsesPublicS3URL552=== RUN TestRedundantMultipartUpload553=== PAUSE TestRedundantMultipartUpload554=== RUN TestCompleteMultipartUpload_ErrorButObjectExists555=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists556=== RUN TestCompletedNarNotReofferedAcrossClosures557=== PAUSE TestCompletedNarNotReofferedAcrossClosures558=== RUN TestPresignedUploadRegisteredBeforeCommit559=== PAUSE TestPresignedUploadRegisteredBeforeCommit560=== RUN TestService_Rustfstest561=== PAUSE TestService_Rustfstest562=== RUN TestParseSize563=== PAUSE TestParseSize564=== RUN TestSkippedUploadsHandler565=== PAUSE TestSkippedUploadsHandler566=== RUN TestSystemdListenerNotActivated567--- PASS: TestSystemdListenerNotActivated (0.00s)568=== RUN TestWatchdogBeatsWhenHealthy569--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)570=== RUN TestWatchdogSkipsWhenUnhealthy5712026/09/15 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/15 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/15 10:24:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/15 10:24:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"581--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)582=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle583=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle584=== RUN TestProxyWriteTimeout585=== PAUSE TestProxyWriteTimeout586=== RUN TestIsValidUploadKey587=== PAUSE TestIsValidUploadKey588=== RUN TestUploadHandlersRejectInvalidKeys589=== PAUSE TestUploadHandlersRejectInvalidKeys590=== RUN TestUploadHandlersRejectOversizedBody591=== PAUSE TestUploadHandlersRejectOversizedBody592=== RUN TestService_cleanupPendingClosuresHandler593=== PAUSE TestService_cleanupPendingClosuresHandler594=== RUN TestService_createPendingClosureHandler595=== PAUSE TestService_createPendingClosureHandler596=== RUN TestService_verifyS3Integrity597=== PAUSE TestService_verifyS3Integrity598=== RUN TestCompleteMultipartUnregistered599=== PAUSE TestCompleteMultipartUnregistered600=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT601=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT602=== CONT TestService_AuthMiddleware603=== CONT TestParseSize604=== CONT TestGCTaskStore_GetEmpty605=== CONT TestUploadHandlersRejectOversizedBody606=== CONT TestResurrectedObjectNotDeleted607=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT608=== CONT TestCompleteMultipartUnregistered609=== CONT TestService_cleanupPendingClosuresHandler610=== CONT TestService_verifyS3Integrity611=== CONT TestProxyWriteTimeout612=== CONT TestUploadHandlersRejectInvalidKeys613=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info614=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info615=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal616=== RUN TestProxyWriteTimeout/narinfo617=== CONT TestIsValidUploadKey618=== PAUSE TestProxyWriteTimeout/narinfo619=== RUN TestIsValidUploadKey/narinfo620=== RUN TestProxyWriteTimeout/1_GiB_nar621=== PAUSE TestProxyWriteTimeout/1_GiB_nar622=== PAUSE TestIsValidUploadKey/narinfo623=== RUN TestIsValidUploadKey/nar_zst624=== CONT TestGCTaskStore_Fail625=== CONT TestPresignedUploadRegisteredBeforeCommit626=== CONT TestGCTaskStore_PhaseUpdates627=== CONT TestCompletedNarNotReofferedAcrossClosures628=== CONT TestGCTaskStore_CompletedAllowsNewTask629=== CONT TestObjectStatsTrigger630=== CONT TestGCTaskStore_GetReturnsLatest631=== CONT TestParseSingleRange632=== RUN TestParseSingleRange/none633=== PAUSE TestParseSingleRange/none634=== RUN TestParseSingleRange/unknown_unit635=== PAUSE TestParseSingleRange/unknown_unit636=== RUN TestParseSingleRange/multi-range_ignored637=== PAUSE TestParseSingleRange/multi-range_ignored638=== RUN TestParseSingleRange/malformed_no_dash639=== PAUSE TestParseSingleRange/malformed_no_dash640=== RUN TestParseSingleRange/malformed_both_empty641=== CONT TestRedundantMultipartUpload642--- PASS: TestParseSize (0.00s)643=== CONT TestOrphanedObjectsGCStressTest644=== CONT TestOrphanedObjectsGC645=== CONT TestService_createPendingClosureHandler646=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal647=== CONT TestGracefulShutdownDrainsInflight648=== CONT TestClaim_StreamsThroughServer649=== CONT TestService_Rustfstest650=== RUN TestProxyWriteTimeout/10_GiB_nar651=== PAUSE TestIsValidUploadKey/nar_zst652=== CONT TestCompleteMultipartUpload_ErrorButObjectExists653=== CONT TestMultipartCleanup654=== CONT TestServerTLSConfig655=== RUN TestServerTLSConfig/no_client_CA656=== PAUSE TestServerTLSConfig/no_client_CA657=== RUN TestServerTLSConfig/missing_CA_file658=== PAUSE TestServerTLSConfig/missing_CA_file659=== RUN TestServerTLSConfig/not_a_PEM_file660=== PAUSE TestServerTLSConfig/not_a_PEM_file661--- PASS: TestGCTaskStore_GetEmpty (0.00s)662--- PASS: TestGCTaskStore_Fail (0.00s)663--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)664--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)665--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)666=== PAUSE TestProxyWriteTimeout/10_GiB_nar667=== RUN TestProxyWriteTimeout/unknown_size668=== PAUSE TestProxyWriteTimeout/unknown_size669=== PAUSE TestParseSingleRange/malformed_both_empty670=== RUN TestParseSingleRange/malformed_end_before_start671=== PAUSE TestParseSingleRange/malformed_end_before_start672=== RUN TestParseSingleRange/closed673=== PAUSE TestParseSingleRange/closed674=== RUN TestParseSingleRange/open-ended675=== PAUSE TestParseSingleRange/open-ended676=== RUN TestParseSingleRange/end_clamped_to_size677=== PAUSE TestParseSingleRange/end_clamped_to_size678=== RUN TestParseSingleRange/suffix679=== PAUSE TestParseSingleRange/suffix680=== RUN TestParseSingleRange/suffix_exceeds_size681=== PAUSE TestParseSingleRange/suffix_exceeds_size682=== RUN TestParseSingleRange/single_byte683=== PAUSE TestParseSingleRange/single_byte684=== RUN TestParseSingleRange/start_past_EOF685=== PAUSE TestParseSingleRange/start_past_EOF686=== RUN TestParseSingleRange/start_far_past_EOF687=== PAUSE TestParseSingleRange/start_far_past_EOF688=== CONT TestReadProxyRangeRequest689=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key690=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key691=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key692=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key693=== CONT TestMetricsInventory694=== CONT TestService_NativeMTLS695=== CONT TestReadRedirectUsesPublicS3URL6962026/09/15 10:24:39 INFO Starting HTTP server address=127.0.0.1:35613697=== RUN TestIsValidUploadKey/nar_xz698=== PAUSE TestIsValidUploadKey/nar_xz699=== RUN TestIsValidUploadKey/nar_plain700=== PAUSE TestIsValidUploadKey/nar_plain701=== RUN TestIsValidUploadKey/listing702=== PAUSE TestIsValidUploadKey/listing703=== RUN TestIsValidUploadKey/build_log704=== PAUSE TestIsValidUploadKey/build_log705=== RUN TestIsValidUploadKey/build_log_home-manager_file706=== PAUSE TestIsValidUploadKey/build_log_home-manager_file707=== RUN TestIsValidUploadKey/build_log_plus_in_name708=== PAUSE TestIsValidUploadKey/build_log_plus_in_name709=== RUN TestIsValidUploadKey/build_log_question_mark710=== PAUSE TestIsValidUploadKey/build_log_question_mark711=== RUN TestIsValidUploadKey/build_log_equals712=== PAUSE TestIsValidUploadKey/build_log_equals713=== RUN TestIsValidUploadKey/realisation714=== PAUSE TestIsValidUploadKey/realisation715=== RUN TestIsValidUploadKey/realisation_plus_in_output716=== PAUSE TestIsValidUploadKey/realisation_plus_in_output7172026/09/15 10:24:39 INFO Shutdown signal received, draining in-flight requests timeout=10s718=== RUN TestIsValidUploadKey/nix-cache-info719=== PAUSE TestIsValidUploadKey/nix-cache-info720=== RUN TestIsValidUploadKey/index.html721=== PAUSE TestIsValidUploadKey/index.html722=== RUN TestIsValidUploadKey/narinfo_key,_nar_type723=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type724=== RUN TestIsValidUploadKey/nar_key,_narinfo_type725=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type726=== RUN TestIsValidUploadKey/listing_key,_narinfo_type727=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type728=== RUN TestIsValidUploadKey/traversal729=== PAUSE TestIsValidUploadKey/traversal730=== RUN TestIsValidUploadKey/traversal_nar731=== PAUSE TestIsValidUploadKey/traversal_nar732=== RUN TestIsValidUploadKey/absolute733=== PAUSE TestIsValidUploadKey/absolute734=== RUN TestIsValidUploadKey/empty_key735=== PAUSE TestIsValidUploadKey/empty_key736=== RUN TestIsValidUploadKey/unknown_type737=== PAUSE TestIsValidUploadKey/unknown_type738=== CONT TestReadRedirectKeepsNarinfoProxied739--- PASS: TestGracefulShutdownDrainsInflight (0.07s)740=== CONT TestNARDeduplicationMetadataUploadBug7412026-09-15 10:24:39.305 UTC [608] ERROR: relation "goose_db_version" does not exist at character 367422026-09-15 10:24:39.305 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7432026-09-15 10:24:39.313 UTC [611] ERROR: relation "goose_db_version" does not exist at character 367442026-09-15 10:24:39.313 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7452026-09-15 10:24:39.314 UTC [612] ERROR: relation "goose_db_version" does not exist at character 367462026-09-15 10:24:39.314 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026-09-15 10:24:39.314 UTC [609] ERROR: relation "goose_db_version" does not exist at character 367482026-09-15 10:24:39.314 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7492026-09-15 10:24:39.314 UTC [610] ERROR: relation "goose_db_version" does not exist at character 367502026-09-15 10:24:39.314 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC751=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure752=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure753=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart754=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart755=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts7562026-09-15 10:24:39.327 UTC [616] ERROR: relation "goose_db_version" does not exist at character 367572026-09-15 10:24:39.327 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026-09-15 10:24:39.327 UTC [613] ERROR: relation "goose_db_version" does not exist at character 367592026-09-15 10:24:39.327 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC760=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts761=== CONT TestReadRedirectNar7622026-09-15 10:24:39.340 UTC [617] ERROR: relation "goose_db_version" does not exist at character 367632026-09-15 10:24:39.340 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7642026/09/15 10:24:39 OK 20241026095416_initial_model.sql (72.68ms)7652026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)7662026/09/15 10:24:39 OK 20241026095416_initial_model.sql (67.01ms)7672026/09/15 10:24:39 OK 20241026095416_initial_model.sql (70.42ms)7682026/09/15 10:24:39 OK 20241026095416_initial_model.sql (64.54ms)7692026/09/15 10:24:39 OK 20241026095416_initial_model.sql (70.69ms)7702026/09/15 10:24:39 OK 20241026095416_initial_model.sql (65.78ms)7712026/09/15 10:24:39 OK 20241026095416_initial_model.sql (68.81ms)7722026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (4.76ms)7732026-09-15 10:24:39.411 UTC [622] ERROR: relation "goose_db_version" does not exist at character 367742026-09-15 10:24:39.411 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026/09/15 10:24:39 OK 20251218171726_add_pins.sql (8.38ms)7762026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.98ms)7772026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (4.71ms)7782026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (4.66ms)7792026/09/15 10:24:39 OK 20241026095416_initial_model.sql (47.04ms)7802026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (4.3ms)7812026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (4.68ms)7822026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.61ms)7832026/09/15 10:24:39 OK 20251218171726_add_pins.sql (8.83ms)7842026/09/15 10:24:39 OK 20251218171726_add_pins.sql (7.38ms)7852026/09/15 10:24:39 OK 20251218171726_add_pins.sql (8.58ms)7862026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (9.04ms)7872026/09/15 10:24:39 OK 20251218171726_add_pins.sql (8.71ms)7882026/09/15 10:24:39 OK 20251218171726_add_pins.sql (10.05ms)7892026/09/15 10:24:39 OK 20251218171726_add_pins.sql (6.15ms)7902026-09-15 10:24:39.431 UTC [624] ERROR: relation "goose_db_version" does not exist at character 367912026-09-15 10:24:39.431 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026-09-15 10:24:39.432 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367932026-09-15 10:24:39.432 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026-09-15 10:24:39.432 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367952026-09-15 10:24:39.432 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026-09-15 10:24:39.433 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367972026-09-15 10:24:39.433 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026/09/15 10:24:39 OK 20251218171726_add_pins.sql (21.03ms)7992026/09/15 10:24:39 OK 20260905000000_add_claims.sql (17.67ms)8002026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (19.07ms)8012026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (17.64ms)8022026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (17.94ms)8032026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (15.22ms)8042026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (16.37ms)8052026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008062026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (17.83ms)8072026/09/15 10:24:39 OK 20241026095416_initial_model.sql (20.04ms)8082026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.3ms)8092026/09/15 10:24:39 OK 1_commit_pending_closure.sql (5.15ms)8102026/09/15 10:24:39 OK 20260905000000_add_claims.sql (6.6ms)8112026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008122026/09/15 10:24:39 OK 20260905000000_add_claims.sql (7.68ms)8132026/09/15 10:24:39 OK 20260905000000_add_claims.sql (7.71ms)8142026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008152026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008162026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (10.87ms)8172026/09/15 10:24:39 OK 20260905000000_add_claims.sql (7.83ms)8182026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008192026/09/15 10:24:39 OK 20260905000000_add_claims.sql (7.96ms)8202026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008212026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.54ms)8222026/09/15 10:24:39 goose: up to current file version: 28232026/09/15 10:24:39 OK 20260905000000_add_claims.sql (8.31ms)8242026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008252026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.96ms)8262026/09/15 10:24:39 OK 1_commit_pending_closure.sql (5.28ms)8272026/09/15 10:24:39 OK 1_commit_pending_closure.sql (5.57ms)8282026/09/15 10:24:39 OK 1_commit_pending_closure.sql (5.68ms)8292026/09/15 10:24:39 OK 1_commit_pending_closure.sql (4.35ms)8302026/09/15 10:24:39 OK 1_commit_pending_closure.sql (5.33ms)8312026/09/15 10:24:39 OK 1_commit_pending_closure.sql (5.17ms)8322026/09/15 10:24:39 OK 20260905000000_add_claims.sql (6.85ms)8332026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008342026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.87ms)8352026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.65ms)8362026/09/15 10:24:39 goose: up to current file version: 28372026/09/15 10:24:39 OK 2_object_stats_trigger.sql (4.28ms)8382026/09/15 10:24:39 goose: up to current file version: 28392026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.81ms)8402026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.91ms)8412026/09/15 10:24:39 goose: up to current file version: 28422026/09/15 10:24:39 goose: up to current file version: 28432026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.96ms)8442026/09/15 10:24:39 goose: up to current file version: 28452026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.75ms)8462026/09/15 10:24:39 goose: up to current file version: 28472026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.84ms)8482026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.84ms)8492026/09/15 10:24:39 goose: up to current file version: 28502026/09/15 10:24:39 OK 20260905000000_add_claims.sql (6.61ms)8512026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008522026/09/15 10:24:39 OK 20241026095416_initial_model.sql (15.58ms)8532026/09/15 10:24:39 OK 20241026095416_initial_model.sql (16.72ms)8542026-09-15 10:24:39.464 UTC [627] ERROR: relation "goose_db_version" does not exist at character 368552026-09-15 10:24:39.464 UTC [627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026/09/15 10:24:39 OK 20241026095416_initial_model.sql (17.38ms)8572026/09/15 10:24:39 OK 20241026095416_initial_model.sql (17.28ms)8582026/09/15 10:24:39 OK 1_commit_pending_closure.sql (10.87ms)8592026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (10.69ms)8602026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (9.94ms)8612026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (9.78ms)8622026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (10.09ms)8632026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.58ms)8642026/09/15 10:24:39 goose: up to current file version: 28652026/09/15 10:24:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"866--- PASS: TestService_AuthMiddleware (0.36s)867=== CONT TestCreatePendingClosureRejectsOversizedNAR8682026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures8692026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.35ms)870--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)871=== CONT TestReadProxyDisabled8722026/09/15 10:24:39 OK 20251218171726_add_pins.sql (6.59ms)8732026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.1ms)8742026/09/15 10:24:39 OK 20251218171726_add_pins.sql (6.37ms)8752026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)8762026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.7ms)8772026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)8782026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)8792026-09-15 10:24:39.489 UTC [629] ERROR: relation "goose_db_version" does not exist at character 368802026-09-15 10:24:39.489 UTC [629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8812026-09-15 10:24:39.490 UTC [630] ERROR: relation "goose_db_version" does not exist at character 368822026-09-15 10:24:39.490 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.89ms)8842026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008852026-09-15 10:24:39.490 UTC [631] ERROR: relation "goose_db_version" does not exist at character 368862026-09-15 10:24:39.490 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8872026-09-15 10:24:39.491 UTC [632] ERROR: relation "goose_db_version" does not exist at character 368882026-09-15 10:24:39.491 UTC [632] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8892026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.92ms)8902026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008912026/09/15 10:24:39 OK 20241026095416_initial_model.sql (14.56ms)8922026/09/15 10:24:39 OK 20260905000000_add_claims.sql (5.28ms)8932026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008942026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.34ms)8952026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000008962026-09-15 10:24:39.492 UTC [633] ERROR: relation "goose_db_version" does not exist at character 368972026-09-15 10:24:39.492 UTC [633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)8992026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.96ms)9002026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.37ms)9012026-09-15 10:24:39.494 UTC [635] ERROR: relation "goose_db_version" does not exist at character 369022026-09-15 10:24:39.494 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026-09-15 10:24:39.495 UTC [636] ERROR: relation "goose_db_version" does not exist at character 369042026-09-15 10:24:39.495 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9052026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.93ms)9062026/09/15 10:24:39 OK 1_commit_pending_closure.sql (4.22ms)9072026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.65ms)9082026/09/15 10:24:39 goose: up to current file version: 29092026-09-15 10:24:39.497 UTC [637] ERROR: relation "goose_db_version" does not exist at character 369102026-09-15 10:24:39.497 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9112026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.44ms)9122026/09/15 10:24:39 goose: up to current file version: 29132026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.49ms)9142026/09/15 10:24:39 goose: up to current file version: 29152026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.08ms)9162026/09/15 10:24:39 OK 2_object_stats_trigger.sql (4.01ms)9172026/09/15 10:24:39 goose: up to current file version: 29182026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (6.77ms)9192026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures9202026-09-15 10:24:39.505 UTC [638] ERROR: relation "goose_db_version" does not exist at character 369212026-09-15 10:24:39.505 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026-09-15 10:24:39.510 UTC [639] ERROR: relation "goose_db_version" does not exist at character 369232026-09-15 10:24:39.510 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026/09/15 10:24:39 OK 20260905000000_add_claims.sql (5.87ms)9252026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009262026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.71ms)9272026/09/15 10:24:39 OK 20241026095416_initial_model.sql (14.83ms)9282026/09/15 10:24:39 OK 20241026095416_initial_model.sql (16.35ms)9292026/09/15 10:24:39 OK 20241026095416_initial_model.sql (14.61ms)9302026/09/15 10:24:39 OK 20241026095416_initial_model.sql (15.17ms)9312026/09/15 10:24:39 OK 1_commit_pending_closure.sql (4.01ms)9322026/09/15 10:24:39 OK 20241026095416_initial_model.sql (16.3ms)9332026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)9342026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9352026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)9362026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)9372026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)9382026/09/15 10:24:39 OK 20241026095416_initial_model.sql (13.58ms)9392026/09/15 10:24:39 OK 20241026095416_initial_model.sql (15.11ms)9402026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)9412026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.97ms)9422026/09/15 10:24:39 goose: up to current file version: 29432026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.99ms)9442026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.04ms)9452026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.75ms)9462026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)9472026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.77ms)9482026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.98ms)9492026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.95ms)9502026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.85ms)9512026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)9522026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.04ms)9532026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.16ms)9542026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)9552026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.27ms)9562026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)9572026/09/15 10:24:39 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9582026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures9592026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (6.29ms)9602026/09/15 10:24:39 OK 20241026095416_initial_model.sql (10.73ms)9612026/09/15 10:24:39 OK 20241026095416_initial_model.sql (13.6ms)9622026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.33ms)9632026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009642026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.65ms)9652026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.59ms)9662026/09/15 10:24:39 goose: successfully migrated database to version: 20260905000000967--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.41s)9682026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)969=== CONT TestCacheConfigHandlerMaxNarSize9702026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)971--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)972=== CONT TestReadProxyRootRedirectsToIndexHTML9732026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.36ms)9742026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009752026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)9762026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.39ms)9772026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.6ms)9782026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009792026/09/15 10:24:39 INFO Received cleanup request method=DELETE path=/api/pending_closures9802026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.39ms)9812026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009822026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.12ms)9832026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.66ms)9842026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.97ms)9852026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009862026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1.9ms)9872026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.81ms)9882026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009892026/09/15 10:24:39 goose: up to current file version: 29902026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.78ms)9912026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3ms)9922026/09/15 10:24:39 OK 20251218171726_add_pins.sql (3.74ms)9932026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.32ms)9942026/09/15 10:24:39 goose: up to current file version: 29952026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.21ms)9962026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.15ms)9972026/09/15 10:24:39 goose: successfully migrated database to version: 202609050000009982026/09/15 10:24:39 INFO Aborted multipart uploads count=09992026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.05ms)10002026/09/15 10:24:39 goose: up to current file version: 210012026/09/15 10:24:39 OK 20251218171726_add_pins.sql (5.39ms)10022026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.53ms)10032026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.46ms)10042026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.46ms)10052026/09/15 10:24:39 goose: up to current file version: 210062026/09/15 10:24:39 OK 2_object_stats_trigger.sql (3.38ms)10072026/09/15 10:24:39 goose: up to current file version: 210082026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures10092026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.36ms)10102026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.15ms)10112026/09/15 10:24:39 goose: up to current file version: 210122026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)10132026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1.78ms)10142026/09/15 10:24:39 goose: up to current file version: 210152026/09/15 10:24:39 OK 2_object_stats_trigger.sql (985.09µs)10162026/09/15 10:24:39 goose: up to current file version: 210172026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)10182026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.33ms)10192026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000010202026/09/15 10:24:39 OK 20260905000000_add_claims.sql (2.87ms)10212026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000010222026/09/15 10:24:39 OK 1_commit_pending_closure.sql (1.83ms)10232026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.94ms)10242026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.15ms)10252026/09/15 10:24:39 goose: up to current file version: 210262026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1.26ms)10272026/09/15 10:24:39 goose: up to current file version: 210282026/09/15 10:24:39 INFO Received cleanup request method=DELETE path=/api/pending_closures10292026-09-15 10:24:39.554 UTC [643] ERROR: relation "goose_db_version" does not exist at character 3610302026-09-15 10:24:39.554 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10312026/09/15 10:24:39 INFO Aborted multipart uploads count=110322026/09/15 10:24:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10332026/09/15 10:24:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10342026-09-15 10:24:39.560 UTC [613] ERROR: Closure does not exist: id=110352026-09-15 10:24:39.560 UTC [613] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10362026-09-15 10:24:39.560 UTC [613] STATEMENT: -- name: CommitPendingClosure :exec1037 SELECT commit_pending_closure($1::bigint)1038 1039--- PASS: TestService_cleanupPendingClosuresHandler (0.44s)1040=== CONT TestGenerateLandingPage10412026/09/15 10:24:39 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1042--- PASS: TestCompleteMultipartUnregistered (0.44s)1043=== CONT TestReadProxyConditionalGet1044--- PASS: TestGenerateLandingPage (0.01s)1045=== CONT TestService_readinessHandler10462026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.72ms)10472026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)10482026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.51ms)10492026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)10502026/09/15 10:24:39 OK 20260905000000_add_claims.sql (10.94ms)10512026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000010522026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.55ms)10532026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.27ms)10542026/09/15 10:24:39 goose: up to current file version: 210552026-09-15 10:24:39.609 UTC [648] ERROR: relation "goose_db_version" does not exist at character 3610562026-09-15 10:24:39.609 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10572026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures1058--- PASS: TestObjectStatsTrigger (0.49s)1059=== CONT TestReadProxyHead1060--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)1061=== CONT TestService_healthCheckHandler10622026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.94ms)10632026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)10642026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.23ms)10652026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)10662026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures10672026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.45ms)10682026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000010692026-09-15 10:24:39.644 UTC [653] ERROR: relation "goose_db_version" does not exist at character 3610702026-09-15 10:24:39.644 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.63ms)10722026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.4ms)10732026/09/15 10:24:39 goose: up to current file version: 210742026-09-15 10:24:39.649 UTC [654] ERROR: relation "goose_db_version" does not exist at character 3610752026-09-15 10:24:39.649 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10762026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.76ms)10772026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)10782026/09/15 10:24:39 OK 20241026095416_initial_model.sql (12.31ms)10792026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.79ms)10802026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)10812026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)10822026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.5ms)10832026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.91ms)10842026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000010852026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)10862026/09/15 10:24:39 OK 1_commit_pending_closure.sql (9.56ms)10872026/09/15 10:24:39 OK 20260905000000_add_claims.sql (8.91ms)10882026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000010892026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1.31ms)10902026/09/15 10:24:39 goose: up to current file version: 210912026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.2ms)10922026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1.03ms)10932026/09/15 10:24:39 goose: up to current file version: 210942026/09/15 10:24:39 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10952026/09/15 10:24:39 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1096--- PASS: TestService_NativeMTLS (0.46s)1097=== CONT TestReadProxyInvalidPath10982026-09-15 10:24:39.700 UTC [655] ERROR: relation "goose_db_version" does not exist at character 3610992026-09-15 10:24:39.700 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11002026-09-15 10:24:39.701 UTC [656] ERROR: relation "goose_db_version" does not exist at character 3611012026-09-15 10:24:39.701 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11022026/09/15 10:24:39 OK 20241026095416_initial_model.sql (12.2ms)11032026/09/15 10:24:39 OK 20241026095416_initial_model.sql (12.15ms)1104--- PASS: TestResurrectedObjectNotDeleted (0.60s)11052026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)1106=== CONT TestReadProxy40411072026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)11082026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.15ms)11092026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.34ms)11102026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)11112026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)11122026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.52ms)11132026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011142026/09/15 10:24:39 OK 20260905000000_add_claims.sql (4.47ms)11152026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011162026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.65ms)11172026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.01ms)11182026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.55ms)11192026/09/15 10:24:39 goose: up to current file version: 211202026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.46ms)11212026/09/15 10:24:39 goose: up to current file version: 21122--- PASS: TestReadProxyRangeRequest (0.51s)1123=== CONT TestClaim_BuildWaitComplete11242026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures11252026-09-15 10:24:39.765 UTC [663] ERROR: relation "goose_db_version" does not exist at character 3611262026-09-15 10:24:39.765 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11272026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures11282026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.28ms)11292026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)11302026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.26ms)11312026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.08ms)11322026-09-15 10:24:39.794 UTC [664] ERROR: relation "goose_db_version" does not exist at character 3611332026-09-15 10:24:39.794 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.83ms)11352026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011362026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.86ms)11372026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1ms)11382026/09/15 10:24:39 goose: up to current file version: 211392026/09/15 10:24:39 OK 20241026095416_initial_model.sql (9.54ms)11402026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)11412026-09-15 10:24:39.812 UTC [665] ERROR: relation "goose_db_version" does not exist at character 3611422026-09-15 10:24:39.812 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/09/15 10:24:39 OK 20251218171726_add_pins.sql (3.7ms)11442026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (3.1ms)11452026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.79ms)11462026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011472026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.05ms)11482026/09/15 10:24:39 OK 2_object_stats_trigger.sql (1.25ms)11492026/09/15 10:24:39 goose: up to current file version: 211502026/09/15 10:24:39 OK 20241026095416_initial_model.sql (9.6ms)11512026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)11522026/09/15 10:24:39 OK 20251218171726_add_pins.sql (3.18ms)1153--- PASS: TestReadRedirectUsesPublicS3URL (0.60s)1154=== CONT TestReadProxyNarStreaming11552026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (2.82ms)11562026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.63ms)11572026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011582026/09/15 10:24:39 OK 1_commit_pending_closure.sql (1.91ms)11592026/09/15 10:24:39 OK 2_object_stats_trigger.sql (847.87µs)11602026/09/15 10:24:39 goose: up to current file version: 21161--- PASS: TestReadProxy404 (0.14s)1162=== CONT TestClaim_InputsTouched11632026/09/15 10:24:39 INFO Received cleanup request method=DELETE path=/api/pending_closures11642026/09/15 10:24:39 INFO Aborted multipart uploads count=11165--- PASS: TestMultipartCleanup (0.66s)1166=== CONT TestReadProxyNarinfoAlreadyDecompressed11672026-09-15 10:24:39.899 UTC [674] ERROR: relation "goose_db_version" does not exist at character 3611682026-09-15 10:24:39.899 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11692026/09/15 10:24:39 OK 20241026095416_initial_model.sql (10.6ms)11702026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)1171--- PASS: TestReadRedirectNar (0.59s)1172=== CONT TestClaim_TwoInstances11732026/09/15 10:24:39 OK 20251218171726_add_pins.sql (4.33ms)1174=== NAME TestNARDeduplicationMetadataUploadBug1175 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug390560830/001/store/63psxf3255s0nykm3l7yw93dbh7vzrfg-file1.txt11762026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)11772026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.94ms)11782026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011792026/09/15 10:24:39 OK 1_commit_pending_closure.sql (3.19ms)11802026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.16ms)11812026/09/15 10:24:39 goose: up to current file version: 211822026-09-15 10:24:39.939 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3611832026-09-15 10:24:39.939 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11842026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.11ms)11852026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)11862026/09/15 10:24:39 OK 20251218171726_add_pins.sql (3.47ms)11872026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures11882026-09-15 10:24:39.965 UTC [713] ERROR: relation "goose_db_version" does not exist at character 3611892026-09-15 10:24:39.965 UTC [713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11902026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)11912026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.6ms)11922026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000011932026/09/15 10:24:39 OK 1_commit_pending_closure.sql (2.52ms)11942026/09/15 10:24:39 OK 2_object_stats_trigger.sql (2.2ms)11952026/09/15 10:24:39 goose: up to current file version: 211962026/09/15 10:24:39 INFO Received uploads request method=POST path=/api/pending_closures11972026/09/15 10:24:39 OK 20241026095416_initial_model.sql (11.99ms)11982026/09/15 10:24:39 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)11992026/09/15 10:24:39 OK 20251218171726_add_pins.sql (3.01ms)12002026/09/15 10:24:39 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)12012026/09/15 10:24:39 OK 20260905000000_add_claims.sql (3.4ms)12022026/09/15 10:24:39 goose: successfully migrated database to version: 2026090500000012032026-09-15 10:24:39.999 UTC [715] ERROR: relation "goose_db_version" does not exist at character 3612042026-09-15 10:24:39.999 UTC [715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12052026/09/15 10:24:40 OK 1_commit_pending_closure.sql (1.96ms)12062026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.07ms)12072026/09/15 10:24:40 goose: up to current file version: 21208--- PASS: TestReadRedirectKeepsNarinfoProxied (0.77s)1209=== CONT TestReadProxyNarinfo12102026/09/15 10:24:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1211--- PASS: TestService_Rustfstest (0.79s)1212=== CONT TestClaim_HolderDisconnectKeepsClaim12132026/09/15 10:24:40 OK 20241026095416_initial_model.sql (14.59ms)12142026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)12152026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.41ms)12162026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)12172026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.26ms)12182026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000012192026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.48ms)12202026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.03ms)12212026/09/15 10:24:40 goose: up to current file version: 212222026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures12232026/09/15 10:24:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12242026/09/15 10:24:40 INFO Uploading 63psxf3255s0nykm3l7yw93dbh7vzrfg-file1.txt (160B)12252026/09/15 10:24:40 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12262026/09/15 10:24:40 WARN Failed to register uploaded object key=63psxf3255s0nykm3l7yw93dbh7vzrfg.ls error="server returned 404: 404 page not found\n"12272026/09/15 10:24:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12282026/09/15 10:24:40 INFO Signed narinfos id=1 count=112292026/09/15 10:24:40 INFO Uploading 1 narinfos12302026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures12312026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures12322026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures12332026/09/15 10:24:40 WARN Failed to register uploaded object key=63psxf3255s0nykm3l7yw93dbh7vzrfg.narinfo error="server returned 404: 404 page not found\n"12342026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12352026/09/15 10:24:40 INFO Completed upload id=112362026/09/15 10:24:40 INFO Upload complete. (112ms)1237=== NAME TestNARDeduplicationMetadataUploadBug1238 metadata_upload_test.go:54: Retrieved narinfo from S3:12392026-09-15 10:24:40.082 UTC [755] ERROR: relation "goose_db_version" does not exist at character 3612402026-09-15 10:24:40.082 UTC [755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1241 StorePath: /build/TestNARDeduplicationMetadataUploadBug390560830/001/store/63psxf3255s0nykm3l7yw93dbh7vzrfg-file1.txt1242 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1243 Compression: zstd1244 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1245 NarSize: 1601246 References: 1247 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1248 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1249 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1250 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12512026-09-15 10:24:40.091 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3612522026-09-15 10:24:40.091 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/09/15 10:24:40 OK 20241026095416_initial_model.sql (10.32ms)12542026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)12552026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.03ms)12562026/09/15 10:24:40 OK 20241026095416_initial_model.sql (10.96ms)12572026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)12582026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)12592026/09/15 10:24:40 OK 20260905000000_add_claims.sql (3.71ms)12602026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000012612026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.26ms)12622026/09/15 10:24:40 OK 1_commit_pending_closure.sql (1.98ms)12632026/09/15 10:24:40 OK 2_object_stats_trigger.sql (836.07µs)12642026/09/15 10:24:40 goose: up to current file version: 212652026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)1266--- PASS: TestMetricsInventory (0.89s)1267=== CONT TestIsValidCachePath1268=== RUN TestIsValidCachePath/narinfo1269=== PAUSE TestIsValidCachePath/narinfo1270=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1271=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1272=== RUN TestIsValidCachePath/nar_zst1273=== PAUSE TestIsValidCachePath/nar_zst1274=== RUN TestIsValidCachePath/nar_xz1275=== PAUSE TestIsValidCachePath/nar_xz1276=== RUN TestIsValidCachePath/nar_bz21277=== PAUSE TestIsValidCachePath/nar_bz21278=== RUN TestIsValidCachePath/nar_uncompressed1279=== PAUSE TestIsValidCachePath/nar_uncompressed1280=== RUN TestIsValidCachePath/ls1281=== PAUSE TestIsValidCachePath/ls1282=== RUN TestIsValidCachePath/log1283=== PAUSE TestIsValidCachePath/log1284=== RUN TestIsValidCachePath/realisation1285=== PAUSE TestIsValidCachePath/realisation1286=== RUN TestIsValidCachePath/nix-cache-info1287=== PAUSE TestIsValidCachePath/nix-cache-info1288=== RUN TestIsValidCachePath/index.html1289=== PAUSE TestIsValidCachePath/index.html1290=== RUN TestIsValidCachePath/traversal_parent1291=== PAUSE TestIsValidCachePath/traversal_parent1292=== RUN TestIsValidCachePath/traversal_in_middle1293=== PAUSE TestIsValidCachePath/traversal_in_middle1294=== RUN TestIsValidCachePath/invalid_char_e1295=== PAUSE TestIsValidCachePath/invalid_char_e1296=== RUN TestIsValidCachePath/invalid_char_u1297=== PAUSE TestIsValidCachePath/invalid_char_u1298=== RUN TestIsValidCachePath/random_path12992026/09/15 10:24:40 OK 20260905000000_add_claims.sql (3.43ms)1300=== PAUSE TestIsValidCachePath/random_path13012026/09/15 10:24:40 goose: successfully migrated database to version: 202609050000001302=== RUN TestIsValidCachePath/empty1303=== PAUSE TestIsValidCachePath/empty1304=== RUN TestIsValidCachePath/leading_slash1305=== PAUSE TestIsValidCachePath/leading_slash1306=== RUN TestIsValidCachePath/wrong_extension1307=== PAUSE TestIsValidCachePath/wrong_extension1308=== RUN TestIsValidCachePath/short_hash1309=== PAUSE TestIsValidCachePath/short_hash1310=== CONT TestClaim_TooManyStreams13112026/09/15 10:24:40 OK 1_commit_pending_closure.sql (1.87ms)13122026/09/15 10:24:40 OK 2_object_stats_trigger.sql (799.21µs)13132026/09/15 10:24:40 goose: up to current file version: 213142026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1315=== NAME TestNARDeduplicationMetadataUploadBug1316 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug390560830/001/store/7nwin1h8wdgwb7ky2gxkhvagsh96xhry-file2.txt13172026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1318--- PASS: TestReadProxyDisabled (0.67s)1319=== CONT TestClaim_GCMarkedOutputCountsAsAbsent13202026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LjZiYjJiZWI4LWE4NjctNDMyYS05MmYwLTk5NDE2YjBmNGQwMHgxNzg5NDY3ODc5NjUyMDM3Mzg2 parts=1013212026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13222026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13232026/09/15 10:24:40 INFO Completed upload id=113242026/09/15 10:24:40 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LmE0ZjNmOGM5LTIwNTAtNGIzNi1hM2ViLTI3ZTgxN2YxZjYxM3gxNzg5NDY3ODgwMTMyMDQ2MzE513252026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures13262026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures13272026/09/15 10:24:40 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13282026/09/15 10:24:40 WARN Found objects in DB but missing from S3, will re-upload count=11329--- PASS: TestService_verifyS3Integrity (1.05s)1330=== CONT TestClaim_StaleHeartbeatStolen13312026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LmE0ZjNmOGM5LTIwNTAtNGIzNi1hM2ViLTI3ZTgxN2YxZjYxM3gxNzg5NDY3ODgwMTMyMDQ2MzE5 parts=11332--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.94s)1333=== CONT TestResolveDBConnectionString1334=== RUN TestResolveDBConnectionString/flag_wins1335=== PAUSE TestResolveDBConnectionString/flag_wins1336=== RUN TestResolveDBConnectionString/file_when_flag_empty1337=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1338=== RUN TestResolveDBConnectionString/missing_file_is_an_error1339=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1340=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1341=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1342=== RUN TestResolveDBConnectionString/nothing_configured1343=== PAUSE TestResolveDBConnectionString/nothing_configured1344=== CONT TestGCTaskStore_StartNew1345--- PASS: TestGCTaskStore_StartNew (0.00s)1346=== CONT TestGCMetrics1347--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.65s)1348=== CONT TestGCTaskStore_ConflictDifferentParams1349--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1350=== CONT TestClaim_FailWakesWaitersButIsNotRemembered13512026/09/15 10:24:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13522026-09-15 10:24:40.198 UTC [836] ERROR: relation "goose_db_version" does not exist at character 3613532026-09-15 10:24:40.198 UTC [836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1354--- PASS: TestReadProxyConditionalGet (0.66s)1355=== CONT TestGCBugBareHashReferences13562026/09/15 10:24:40 OK 20241026095416_initial_model.sql (17.19ms)13572026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures13582026/09/15 10:24:40 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13592026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)13602026/09/15 10:24:40 WARN readiness check failed error="closed pool"1361--- PASS: TestService_readinessHandler (0.67s)1362=== CONT TestGCTaskStore_DeduplicateSameParams1363--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1364=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13652026-09-15 10:24:40.245 UTC [857] ERROR: relation "goose_db_version" does not exist at character 3613662026-09-15 10:24:40.245 UTC [857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13672026/09/15 10:24:40 OK 20251218171726_add_pins.sql (6.26ms)13682026/09/15 10:24:40 WARN Failed to register uploaded object key=7nwin1h8wdgwb7ky2gxkhvagsh96xhry.ls error="server returned 404: 404 page not found\n"13692026/09/15 10:24:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13702026/09/15 10:24:40 INFO Signed narinfos id=2 count=113712026/09/15 10:24:40 INFO Uploading 1 narinfos13722026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (6.8ms)13732026/09/15 10:24:40 WARN Failed to register uploaded object key=7nwin1h8wdgwb7ky2gxkhvagsh96xhry.narinfo error="server returned 404: 404 page not found\n"13742026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13752026/09/15 10:24:40 OK 20260905000000_add_claims.sql (8.28ms)13762026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000013772026/09/15 10:24:40 INFO Completed upload id=213782026/09/15 10:24:40 INFO Upload complete. (105ms)1379=== NAME TestNARDeduplicationMetadataUploadBug1380 metadata_upload_test.go:76: Retrieved narinfo from S3:1381 StorePath: /build/TestNARDeduplicationMetadataUploadBug390560830/001/store/7nwin1h8wdgwb7ky2gxkhvagsh96xhry-file2.txt1382 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1383 Compression: zstd1384 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1385 NarSize: 1601386 References: 1387 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13882026/09/15 10:24:40 OK 1_commit_pending_closure.sql (4.16ms)1389 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1390 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1391 {"version":1,"root":{"type":"regular","size":44}}1392--- PASS: TestNARDeduplicationMetadataUploadBug (0.97s)1393=== CONT TestClaim_FailWithoutKindReleases13942026/09/15 10:24:40 OK 2_object_stats_trigger.sql (10.05ms)13952026/09/15 10:24:40 goose: up to current file version: 213962026/09/15 10:24:40 OK 20241026095416_initial_model.sql (15.74ms)13972026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (4.12ms)13982026-09-15 10:24:40.285 UTC [861] ERROR: relation "goose_db_version" does not exist at character 3613992026-09-15 10:24:40.285 UTC [861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14002026/09/15 10:24:40 OK 20251218171726_add_pins.sql (5.03ms)14012026-09-15 10:24:40.287 UTC [863] ERROR: relation "goose_db_version" does not exist at character 3614022026-09-15 10:24:40.287 UTC [863] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14032026-09-15 10:24:40.287 UTC [864] ERROR: relation "goose_db_version" does not exist at character 3614042026-09-15 10:24:40.287 UTC [864] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14052026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (5.73ms)1406--- PASS: TestReadProxyHead (0.68s)1407=== CONT TestClientMultipleUploads14082026/09/15 10:24:40 OK 20260905000000_add_claims.sql (5.22ms)14092026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000014102026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.71ms)14112026/09/15 10:24:40 OK 2_object_stats_trigger.sql (3.24ms)14122026/09/15 10:24:40 goose: up to current file version: 214132026/09/15 10:24:40 OK 20241026095416_initial_model.sql (13.1ms)14142026/09/15 10:24:40 OK 20241026095416_initial_model.sql (14.1ms)14152026/09/15 10:24:40 OK 20241026095416_initial_model.sql (14ms)14162026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)14172026-09-15 10:24:40.310 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3614182026-09-15 10:24:40.310 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14192026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)14202026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)14212026/09/15 10:24:40 OK 20251218171726_add_pins.sql (5.1ms)14222026/09/15 10:24:40 OK 20251218171726_add_pins.sql (5.51ms)14232026/09/15 10:24:40 OK 20251218171726_add_pins.sql (5.48ms)1424--- PASS: TestService_healthCheckHandler (0.69s)1425=== CONT TestPinProtectsFromGC14262026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)14272026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)14282026/09/15 10:24:40 OK 20260905000000_add_claims.sql (5.39ms)14292026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000014302026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (7.22ms)14312026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.88ms)14322026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000014332026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.2ms)14342026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.96ms)14352026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.36ms)14362026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000014372026/09/15 10:24:40 OK 20241026095416_initial_model.sql (13.64ms)14382026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.11ms)14392026/09/15 10:24:40 goose: up to current file version: 214402026/09/15 10:24:40 OK 2_object_stats_trigger.sql (3.31ms)14412026/09/15 10:24:40 goose: up to current file version: 214422026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.15ms)14432026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)14442026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.53ms)14452026/09/15 10:24:40 goose: up to current file version: 214462026-09-15 10:24:40.338 UTC [870] ERROR: relation "goose_db_version" does not exist at character 3614472026-09-15 10:24:40.338 UTC [870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.95ms)14492026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)1450--- PASS: TestReadProxyInvalidPath (0.66s)1451=== CONT TestClientWithDependencies14522026/09/15 10:24:40 OK 20260905000000_add_claims.sql (11.55ms)14532026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000014542026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.44ms)14552026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.84ms)14562026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)14572026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.35ms)14582026/09/15 10:24:40 goose: up to current file version: 214592026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.12ms)14602026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)14612026-09-15 10:24:40.372 UTC [874] ERROR: relation "goose_db_version" does not exist at character 3614622026-09-15 10:24:40.372 UTC [874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14632026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14642026-09-15 10:24:40.372 UTC [873] ERROR: relation "goose_db_version" does not exist at character 3614652026-09-15 10:24:40.372 UTC [873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14662026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.76ms)14672026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000014682026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.93ms)14692026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.51ms)14702026/09/15 10:24:40 goose: up to current file version: 214712026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"14722026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.38ms)14732026/09/15 10:24:40 OK 20241026095416_initial_model.sql (13ms)14742026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)14752026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)14762026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"14772026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"14782026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.74ms)14792026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures14802026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.63ms)14812026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LjcxZjhlN2VlLTNhYzItNDc2Ny1iNTllLWJlY2QwY2FhYTBjOHgxNzg5NDY3ODc5NzkwNDg5NTc4 parts=1214822026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures14832026-09-15 10:24:40.400 UTC [876] ERROR: relation "goose_db_version" does not exist at character 3614842026-09-15 10:24:40.400 UTC [876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14852026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (5ms)1486=== NAME TestOrphanedObjectsGC1487 orphaned_objects_gc_test.go:290: GC Test Summary:1488 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1489 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1490 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1491 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1492 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1493--- PASS: TestOrphanedObjectsGC (1.17s)1494=== CONT TestSkippedUploadsHandler14952026/09/15 10:24:40 INFO Client skipped oversized paths paths=3 nar_bytes=500000000014962026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)1497--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.18s)1498=== CONT TestClientErrorHandling1499=== RUN TestClientErrorHandling/InvalidStorePath1500=== PAUSE TestClientErrorHandling/InvalidStorePath1501=== RUN TestClientErrorHandling/InvalidAuthToken1502=== PAUSE TestClientErrorHandling/InvalidAuthToken1503=== RUN TestClientErrorHandling/ServerNotAvailable1504=== PAUSE TestClientErrorHandling/ServerNotAvailable1505=== CONT TestClientCADerivations1506--- PASS: TestSkippedUploadsHandler (0.00s)15072026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.46ms)1508=== CONT TestClientIntegration15092026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015102026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.57ms)15112026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015122026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.03ms)15132026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.09ms)15142026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.29ms)15152026/09/15 10:24:40 goose: up to current file version: 215162026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.41ms)15172026/09/15 10:24:40 goose: up to current file version: 215182026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.17ms)15192026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)15202026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.94ms)1521--- PASS: TestReadProxyNarStreaming (0.59s)1522=== CONT TestService_RequireScope_OIDC15232026/09/15 10:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44097/oidc15242026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)15252026-09-15 10:24:40.431 UTC [881] ERROR: relation "goose_db_version" does not exist at character 3615262026-09-15 10:24:40.431 UTC [881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15272026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.94ms)15282026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015292026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.65ms)15302026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.93ms)15312026/09/15 10:24:40 goose: up to current file version: 215322026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures15332026/09/15 10:24:40 OK 20241026095416_initial_model.sql (13.86ms)15342026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)15352026/09/15 10:24:40 OK 20251218171726_add_pins.sql (12.56ms)15362026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (6.69ms)15372026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.46ms)15382026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015392026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.98ms)1540--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.60s)1541=== CONT TestCacheConfigHandler1542=== RUN TestCacheConfigHandler/full_config,_no_issuer1543=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1544=== RUN TestCacheConfigHandler/no_cache_url_configured1545=== PAUSE TestCacheConfigHandler/no_cache_url_configured1546=== RUN TestCacheConfigHandler/no_signing_keys1547=== PAUSE TestCacheConfigHandler/no_signing_keys1548=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1549=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1550=== CONT TestService_ReadScope_PublicByDefault15512026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.17ms)15522026/09/15 10:24:40 goose: up to current file version: 215532026-09-15 10:24:40.490 UTC [885] ERROR: relation "goose_db_version" does not exist at character 3615542026-09-15 10:24:40.490 UTC [885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15552026-09-15 10:24:40.491 UTC [886] ERROR: relation "goose_db_version" does not exist at character 3615562026-09-15 10:24:40.491 UTC [886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15572026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"15582026/09/15 10:24:40 OK 20241026095416_initial_model.sql (11.69ms)15592026-09-15 10:24:40.509 UTC [889] ERROR: relation "goose_db_version" does not exist at character 3615602026-09-15 10:24:40.509 UTC [889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15612026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.62ms)15622026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)15632026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)15642026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"15652026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.23ms)15662026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.34ms)15672026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)15682026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)15692026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"15702026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures15712026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.29ms)15722026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015732026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.46ms)15742026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015752026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.09ms)15762026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.12ms)15772026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.76ms)15782026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.85ms)15792026/09/15 10:24:40 goose: up to current file version: 215802026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)15812026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.74ms)15822026/09/15 10:24:40 goose: up to current file version: 215832026/09/15 10:24:40 OK 20251218171726_add_pins.sql (5.17ms)1584--- PASS: TestReadProxyNarinfo (0.54s)1585=== CONT TestCacheStatsHandler15862026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)15872026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.26ms)15882026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000015892026/09/15 10:24:40 OK 1_commit_pending_closure.sql (1.96ms)15902026/09/15 10:24:40 OK 2_object_stats_trigger.sql (942.39µs)15912026/09/15 10:24:40 goose: up to current file version: 215922026-09-15 10:24:40.558 UTC [895] ERROR: relation "goose_db_version" does not exist at character 3615932026-09-15 10:24:40.558 UTC [895] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15942026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"15952026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15962026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15972026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"15982026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.13ms)15992026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)16002026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4Ljk4ZGUxNDVmLTIxNTAtNDE0ZC1hMjdlLTg5N2RlNDEyY2YxNXgxNzg5NDY3ODgwMDgyMDgxMDg5 parts=1016012026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16022026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.17ms)16032026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"16042026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)16052026/09/15 10:24:40 INFO Completed upload id=116062026/09/15 10:24:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016072026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LmYyMDkzNmNkLTIzNmUtNDUwZC1iYTc3LWI1ZjJkMWRlOGNmZXgxNzg5NDY3ODc5OTc2NTM1ODAw parts=1216082026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1609--- PASS: TestRedundantMultipartUpload (1.36s)1610=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16112026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.06ms)16122026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000016132026/09/15 10:24:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures16142026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.91ms)16152026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.13ms)16162026/09/15 10:24:40 goose: up to current file version: 21617--- PASS: TestClaim_TooManyStreams (0.48s)1618=== CONT TestService_AuthMiddleware_OIDC16192026/09/15 10:24:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43929/oidc16202026/09/15 10:24:40 INFO Aborted multipart uploads count=016212026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures16222026/09/15 10:24:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=016232026-09-15 10:24:40.624 UTC [903] ERROR: relation "goose_db_version" does not exist at character 3616242026-09-15 10:24:40.624 UTC [903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16252026/09/15 10:24:40 INFO Vacuumed table table=pending_closures16262026/09/15 10:24:40 INFO Vacuumed table table=pending_objects16272026/09/15 10:24:40 INFO Vacuumed table table=multipart_uploads16282026/09/15 10:24:40 INFO Vacuumed table table=closures16292026/09/15 10:24:40 INFO Vacuumed table table=objects16302026/09/15 10:24:40 OK 20241026095416_initial_model.sql (11.87ms)16312026/09/15 10:24:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016322026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)1633--- PASS: TestService_createPendingClosureHandler (1.42s)1634=== CONT TestService_AuthMiddleware_MTLSProxyHeader16352026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"16362026/09/15 10:24:40 OK 20251218171726_add_pins.sql (4.3ms)16372026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (5.07ms)16382026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4ms)16392026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000016402026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"16412026/09/15 10:24:40 OK 1_commit_pending_closure.sql (4.09ms)16422026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"16432026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.94ms)16442026/09/15 10:24:40 goose: up to current file version: 21645--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (0.48s)1646=== CONT TestService_ReadAuthMiddleware16472026-09-15 10:24:40.671 UTC [908] ERROR: relation "goose_db_version" does not exist at character 3616482026-09-15 10:24:40.671 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16492026-09-15 10:24:40.684 UTC [911] ERROR: relation "goose_db_version" does not exist at character 3616502026-09-15 10:24:40.684 UTC [911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16512026/09/15 10:24:40 INFO Aborted multipart uploads count=016522026/09/15 10:24:40 WARN Force mode enabled - objects will be deleted immediately without grace period16532026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.79ms)16542026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)16552026/09/15 10:24:40 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=016562026/09/15 10:24:40 INFO Vacuumed table table=pending_closures16572026/09/15 10:24:40 INFO Vacuumed table table=pending_objects16582026/09/15 10:24:40 INFO Vacuumed table table=multipart_uploads16592026/09/15 10:24:40 INFO Vacuumed table table=closures16602026/09/15 10:24:40 INFO Vacuumed table table=objects16612026/09/15 10:24:40 OK 20251218171726_add_pins.sql (5.22ms)16622026/09/15 10:24:40 OK 20241026095416_initial_model.sql (12.44ms)1663--- PASS: TestGCMetrics (0.53s)1664=== CONT TestServerTLSConfig/no_client_CA1665=== CONT TestProxyWriteTimeout/narinfo1666=== CONT TestParseSingleRange/none1667=== CONT TestParseSingleRange/open-ended16682026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)1669=== CONT TestParseSingleRange/start_far_past_EOF1670=== CONT TestParseSingleRange/start_past_EOF1671=== CONT TestParseSingleRange/single_byte1672=== CONT TestParseSingleRange/suffix_exceeds_size1673=== CONT TestParseSingleRange/suffix1674=== CONT TestParseSingleRange/end_clamped_to_size1675=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16762026/09/15 10:24:40 INFO Received uploads request method=POST path=/1677=== CONT TestProxyWriteTimeout/unknown_size1678=== CONT TestServerTLSConfig/not_a_PEM_file1679=== CONT TestParseSingleRange/malformed_both_empty1680=== CONT TestParseSingleRange/closed1681=== CONT TestParseSingleRange/malformed_end_before_start16822026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)1683=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16842026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/1685=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16862026/09/15 10:24:40 INFO Received request for more parts method=POST path=/1687=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16882026/09/15 10:24:40 INFO Received uploads request method=POST path=/1689=== CONT TestParseSingleRange/multi-range_ignored1690--- PASS: TestUploadHandlersRejectInvalidKeys (0.11s)1691 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1692 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1693 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1694 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1695=== CONT TestParseSingleRange/malformed_no_dash1696=== CONT TestProxyWriteTimeout/1_GiB_nar1697=== CONT TestServerTLSConfig/missing_CA_file1698--- PASS: TestServerTLSConfig (0.00s)1699 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1700 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1701 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1702=== CONT TestProxyWriteTimeout/10_GiB_nar1703--- PASS: TestProxyWriteTimeout (0.11s)1704 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1705 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1706 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1707 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1708=== CONT TestParseSingleRange/unknown_unit1709--- PASS: TestParseSingleRange (0.00s)1710 --- PASS: TestParseSingleRange/none (0.00s)1711 --- PASS: TestParseSingleRange/open-ended (0.00s)1712 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1713 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1714 --- PASS: TestParseSingleRange/single_byte (0.00s)1715 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1716 --- PASS: TestParseSingleRange/suffix (0.00s)1717 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1718 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1719 --- PASS: TestParseSingleRange/closed (0.00s)1720 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1721 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1722 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1723 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1724=== CONT TestIsValidUploadKey/narinfo1725=== CONT TestIsValidUploadKey/realisation_plus_in_output1726=== CONT TestIsValidUploadKey/unknown_type1727=== CONT TestIsValidUploadKey/empty_key1728=== CONT TestIsValidUploadKey/absolute1729=== CONT TestIsValidUploadKey/traversal_nar1730=== CONT TestIsValidUploadKey/traversal1731=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1732=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1733=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1734=== CONT TestIsValidUploadKey/index.html1735=== CONT TestIsValidUploadKey/nix-cache-info1736=== CONT TestIsValidUploadKey/build_log_home-manager_file1737=== CONT TestIsValidUploadKey/build_log_equals1738=== CONT TestIsValidUploadKey/build_log_question_mark1739=== CONT TestIsValidUploadKey/realisation1740=== CONT TestIsValidUploadKey/build_log_plus_in_name1741=== CONT TestIsValidUploadKey/nar_plain1742=== CONT TestIsValidUploadKey/nar_xz1743=== CONT TestIsValidUploadKey/build_log1744=== CONT TestIsValidUploadKey/listing1745=== CONT TestIsValidUploadKey/nar_zst1746=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17472026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"1748--- PASS: TestIsValidUploadKey (0.11s)1749 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1750 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1751 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1752 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1753 --- PASS: TestIsValidUploadKey/absolute (0.00s)1754 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1755 --- PASS: TestIsValidUploadKey/traversal (0.00s)1756 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1757 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1758 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1759 --- PASS: TestIsValidUploadKey/index.html (0.00s)1760 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1761 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1762 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1763 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1764 --- PASS: TestIsValidUploadKey/realisation (0.00s)1765 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1766 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1767 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1768 --- PASS: TestIsValidUploadKey/build_log (0.00s)1769 --- PASS: TestIsValidUploadKey/listing (0.00s)1770 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)17712026/09/15 10:24:40 INFO Received uploads request method=POST path=/17722026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.19ms)17732026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000017742026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.74ms)17752026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.87ms)17762026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.73ms)17772026/09/15 10:24:40 goose: up to current file version: 217782026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)17792026/09/15 10:24:40 OK 20260905000000_add_claims.sql (10.49ms)17802026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000017812026-09-15 10:24:40.727 UTC [914] ERROR: relation "goose_db_version" does not exist at character 3617822026-09-15 10:24:40.727 UTC [914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17832026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"17842026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.91ms)1785--- PASS: TestClaim_StaleHeartbeatStolen (0.56s)1786=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17872026/09/15 10:24:40 INFO Received request for more parts method=POST path=/17882026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.72ms)17892026/09/15 10:24:40 goose: up to current file version: 217902026/09/15 10:24:40 OK 20241026095416_initial_model.sql (9.76ms)17912026-09-15 10:24:40.743 UTC [915] ERROR: relation "goose_db_version" does not exist at character 3617922026-09-15 10:24:40.743 UTC [915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17932026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)17942026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.91ms)17952026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)17962026/09/15 10:24:40 OK 20260905000000_add_claims.sql (3.58ms)17972026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000017982026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.42ms)17992026/09/15 10:24:40 OK 20241026095416_initial_model.sql (9.66ms)18002026/09/15 10:24:40 OK 2_object_stats_trigger.sql (1.58ms)18012026/09/15 10:24:40 goose: up to current file version: 218022026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures18032026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)18042026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.19ms)18052026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)18062026/09/15 10:24:40 OK 20260905000000_add_claims.sql (2.75ms)18072026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000018082026/09/15 10:24:40 OK 1_commit_pending_closure.sql (2.04ms)18092026/09/15 10:24:40 OK 2_object_stats_trigger.sql (865.73µs)18102026/09/15 10:24:40 goose: up to current file version: 218112026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"18122026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"1813--- PASS: TestClaim_FailWithoutKindReleases (0.55s)1814=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18152026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/1816=== NAME TestClientMultipleUploads1817 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads1456781521/001/store/43sgklw72id9a247fw9w02fp8x6n3zq1-test-file-0.txt1818=== CONT TestIsValidCachePath/wrong_extension1819=== CONT TestIsValidCachePath/narinfo1820=== CONT TestIsValidCachePath/leading_slash1821=== CONT TestIsValidCachePath/empty1822=== CONT TestIsValidCachePath/random_path1823=== CONT TestIsValidCachePath/invalid_char_u1824=== CONT TestIsValidCachePath/invalid_char_e1825=== CONT TestIsValidCachePath/ls1826=== CONT TestIsValidCachePath/nar_uncompressed1827=== CONT TestIsValidCachePath/nar_bz21828=== CONT TestIsValidCachePath/nar_xz1829=== CONT TestIsValidCachePath/nar_zst1830=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1831=== CONT TestIsValidCachePath/short_hash1832=== CONT TestIsValidCachePath/log1833=== CONT TestIsValidCachePath/index.html1834=== CONT TestIsValidCachePath/traversal_in_middle1835=== CONT TestIsValidCachePath/traversal_parent1836=== CONT TestIsValidCachePath/nix-cache-info1837=== CONT TestIsValidCachePath/realisation1838--- PASS: TestIsValidCachePath (0.00s)1839 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1840 --- PASS: TestIsValidCachePath/narinfo (0.00s)1841 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1842 --- PASS: TestIsValidCachePath/empty (0.00s)1843 --- PASS: TestIsValidCachePath/random_path (0.00s)1844 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1845 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1846 --- PASS: TestIsValidCachePath/ls (0.00s)1847 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1848 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1849 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1850 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1851 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1852 --- PASS: TestIsValidCachePath/short_hash (0.00s)1853 --- PASS: TestIsValidCachePath/log (0.00s)1854 --- PASS: TestIsValidCachePath/index.html (0.00s)1855 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1856 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1857 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1858 --- PASS: TestIsValidCachePath/realisation (0.00s)1859=== CONT TestResolveDBConnectionString/flag_wins1860=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1861=== CONT TestResolveDBConnectionString/nothing_configured1862=== CONT TestResolveDBConnectionString/missing_file_is_an_error1863=== CONT TestResolveDBConnectionString/file_when_flag_empty1864=== CONT TestClientErrorHandling/InvalidStorePath1865--- PASS: TestResolveDBConnectionString (0.00s)1866 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1867 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1868 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1869 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1870 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1871=== NAME TestClientMultipleUploads1872 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads1456781521/001/store/4lz05fzz65zy3gdjbvy6d8y76py5ddff-test-file-1.txt18732026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18742026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1875 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads1456781521/001/store/9mbvf0q4gzvp0l344z66cadpk5njbzz7-test-file-2.txt18762026-09-15 10:24:40.901 UTC [990] ERROR: relation "goose_db_version" does not exist at character 3618772026-09-15 10:24:40.901 UTC [990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18782026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LmIwNjdlZWU4LWE4OWYtNGMwYi1iZDU3LWIwNjJjM2M4NGU4ZXgxNzg5NDY3ODgwNDA2MDU1OTM4 parts=1018792026/09/15 10:24:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18802026/09/15 10:24:40 INFO Signed narinfos id=1 count=118812026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1882=== CONT TestClientErrorHandling/InvalidAuthToken18832026/09/15 10:24:40 INFO Received uploads request method=POST path=/api/pending_closures1884=== NAME TestPinProtectsFromGC1885 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC4248580417/001/store/kxq4plzdl1rmw3fxsnd78q591lxr4fgw-pinned-file.txt1886 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC4248580417/001/store/5r16y60s9wijdnn8drbzyimrj4bnz99a-unpinned-file.txt18872026/09/15 10:24:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18882026/09/15 10:24:40 INFO Signed narinfos id=2 count=118892026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18902026/09/15 10:24:40 OK 20241026095416_initial_model.sql (11.46ms)18912026/09/15 10:24:40 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)18922026/09/15 10:24:40 INFO Completed upload id=218932026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"18942026/09/15 10:24:40 OK 20251218171726_add_pins.sql (3.16ms)1895--- PASS: TestClaim_BuildWaitComplete (1.18s)1896=== CONT TestClientErrorHandling/ServerNotAvailable18972026/09/15 10:24:40 OK 20260628120000_add_object_size_and_stats.sql (3.71ms)18982026/09/15 10:24:40 OK 20260905000000_add_claims.sql (4.84ms)18992026/09/15 10:24:40 goose: successfully migrated database to version: 2026090500000019002026/09/15 10:24:40 OK 1_commit_pending_closure.sql (3.6ms)1901=== NAME TestClientIntegration1902 client_integration_test.go:277: Created store path: /build/TestClientIntegration4272763436/002/store/xx7mxs6r1jc3j1pds8x1azc6glsqjm2a-test-file.txt19032026/09/15 10:24:40 OK 2_object_stats_trigger.sql (2.71ms)19042026/09/15 10:24:40 goose: up to current file version: 219052026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1906=== NAME TestClientWithDependencies1907 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies2132968689/001/store/iha6cqvdzmsmab0mv8r8nyd2r6pyglld-test-script1908--- PASS: TestGCBugBareHashReferences (0.74s)1909=== CONT TestCacheConfigHandler/full_config,_no_issuer1910=== CONT TestCacheConfigHandler/no_signing_keys1911=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1912=== CONT TestCacheConfigHandler/no_cache_url_configured1913--- PASS: TestCacheConfigHandler (0.00s)1914 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1915 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1916 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1917 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)19182026/09/15 10:24:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LmRhMDAwYWEyLTExMjMtNGZkZi1iNzlkLTRjZjlkNDQxMjViN3gxNzg5NDY3ODgwNDcwNjc1MTU1 parts=1019192026/09/15 10:24:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1920--- PASS: TestService_ReadScope_PublicByDefault (0.49s)19212026/09/15 10:24:40 INFO Completed upload id=119222026/09/15 10:24:40 WARN claim: cannot clear write deadline error="feature not supported"1923=== NAME TestClientWithDependencies1924 client_integration_test.go:596: Found 1 dependencies (including self)19252026-09-15 10:24:40.983 UTC [1155] ERROR: relation "goose_db_version" does not exist at character 3619262026-09-15 10:24:40.983 UTC [1155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19272026/09/15 10:24:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1928=== RUN TestService_RequireScope_OIDC/builder_may_write1929=== PAUSE TestService_RequireScope_OIDC/builder_may_write1930=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1931=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1932=== RUN TestService_RequireScope_OIDC/ops_may_admin1933=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1934=== RUN TestService_RequireScope_OIDC/ops_may_not_write1935=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1936=== RUN TestService_RequireScope_OIDC/reader_may_not_write1937=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1938=== RUN TestService_RequireScope_OIDC/static_token_may_admin1939=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1940=== RUN TestService_RequireScope_OIDC/static_token_may_write1941=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1942=== RUN TestService_RequireScope_OIDC/reader_may_read1943=== PAUSE TestService_RequireScope_OIDC/reader_may_read1944=== RUN TestService_RequireScope_OIDC/writer_implies_read1945=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1946=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1947=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1948=== CONT TestService_RequireScope_OIDC/builder_may_write1949=== CONT TestService_RequireScope_OIDC/writer_implies_read1950=== CONT TestService_RequireScope_OIDC/reader_may_not_write19512026/09/15 10:24:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19522026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[read]19532026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[write]1954=== CONT TestService_RequireScope_OIDC/reader_may_read19552026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[write]1956=== CONT TestService_RequireScope_OIDC/static_token_may_write1957=== CONT TestService_RequireScope_OIDC/static_token_may_admin1958=== CONT TestService_RequireScope_OIDC/ops_may_admin1959=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1960=== CONT TestService_RequireScope_OIDC/ops_may_not_write19612026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[admin]1962=== CONT TestService_RequireScope_OIDC/builder_may_not_admin19632026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[read]19642026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[write]19652026/09/15 10:24:40 INFO OIDC auth successful provider=test scopes=[admin]19662026/09/15 10:24:40 INFO Aborted multipart uploads count=01967--- PASS: TestService_RequireScope_OIDC (0.56s)1968 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1969 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1970 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1971 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1972 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1973 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1974 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1975 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1976 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1977 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)19782026/09/15 10:24:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19792026/09/15 10:24:40 WARN Force mode enabled - objects will be deleted immediately without grace period19802026/09/15 10:24:40 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=019812026/09/15 10:24:40 INFO Vacuumed table table=pending_closures19822026/09/15 10:24:41 INFO Vacuumed table table=pending_objects19832026/09/15 10:24:41 OK 20241026095416_initial_model.sql (9.7ms)19842026/09/15 10:24:41 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)19852026/09/15 10:24:41 INFO Vacuumed table table=multipart_uploads19862026/09/15 10:24:41 INFO Vacuumed table table=closures19872026/09/15 10:24:41 INFO Vacuumed table table=objects19882026/09/15 10:24:41 OK 20251218171726_add_pins.sql (3.26ms)1989--- PASS: TestClaim_InputsTouched (1.15s)19902026/09/15 10:24:41 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)19912026/09/15 10:24:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19922026/09/15 10:24:41 OK 20260905000000_add_claims.sql (3.24ms)19932026/09/15 10:24:41 goose: successfully migrated database to version: 202609050000001994--- PASS: TestCacheStatsHandler (0.47s)19952026/09/15 10:24:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LmZmMDVkMmYwLWU5ZWMtNGYwYi05M2FkLTA5MTBhYmE0NzUzYngxNzg5NDY3ODgwNTMxNTk4Mjk5 parts=1019962026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19972026/09/15 10:24:41 INFO Signed narinfos id=1 count=119982026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19992026/09/15 10:24:41 OK 1_commit_pending_closure.sql (2.26ms)20002026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures20012026/09/15 10:24:41 OK 2_object_stats_trigger.sql (1.08ms)20022026/09/15 10:24:41 goose: up to current file version: 220032026/09/15 10:24:41 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-config20042026/09/15 10:24:41 INFO Completed upload id=120052026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures20062026/09/15 10:24:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20072026/09/15 10:24:41 INFO Uploading kxq4plzdl1rmw3fxsnd78q591lxr4fgw-pinned-file.txt (128B)2008--- PASS: TestClaim_TwoInstances (1.10s)2009=== NAME TestClientCADerivations2010 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3189843515/001/store/0xczfhwddly0fqr249dgb7iyynyygs2c-ca-test20112026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures20122026/09/15 10:24:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20132026/09/15 10:24:41 WARN mTLS auth: bound subjects configured but subject DN unavailable20142026/09/15 10:24:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"20152026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"2016--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.44s)20172026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures20182026/09/15 10:24:41 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20192026/09/15 10:24:41 INFO Uploading 43sgklw72id9a247fw9w02fp8x6n3zq1-test-file-0.txt (160B)20202026/09/15 10:24:41 INFO Uploading 9mbvf0q4gzvp0l344z66cadpk5njbzz7-test-file-2.txt (160B)20212026/09/15 10:24:41 INFO Uploading 4lz05fzz65zy3gdjbvy6d8y76py5ddff-test-file-1.txt (160B)20222026/09/15 10:24:41 WARN Failed to register uploaded object key=kxq4plzdl1rmw3fxsnd78q591lxr4fgw.ls error="server returned 404: 404 page not found\n"20232026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20242026/09/15 10:24:41 INFO Signed narinfos id=1 count=120252026/09/15 10:24:41 INFO Uploading 1 narinfos20262026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20272026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20282026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20292026/09/15 10:24:41 WARN Failed to register uploaded object key=kxq4plzdl1rmw3fxsnd78q591lxr4fgw.narinfo error="server returned 404: 404 page not found\n"20302026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20312026/09/15 10:24:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20322026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures20332026/09/15 10:24:41 WARN Failed to register uploaded object key=9mbvf0q4gzvp0l344z66cadpk5njbzz7.ls error="server returned 404: 404 page not found\n"20342026/09/15 10:24:41 WARN Failed to register uploaded object key=43sgklw72id9a247fw9w02fp8x6n3zq1.ls error="server returned 404: 404 page not found\n"20352026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures20362026/09/15 10:24:41 WARN Failed to register uploaded object key=4lz05fzz65zy3gdjbvy6d8y76py5ddff.ls error="server returned 404: 404 page not found\n"20372026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20382026/09/15 10:24:41 INFO Signed narinfos id=3 count=120392026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20402026/09/15 10:24:41 INFO Signed narinfos id=1 count=120412026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20422026/09/15 10:24:41 INFO Signed narinfos id=2 count=120432026/09/15 10:24:41 INFO Uploading 3 narinfos20442026/09/15 10:24:41 INFO Completed upload id=120452026/09/15 10:24:41 INFO Upload complete. (101ms)20462026/09/15 10:24:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20472026/09/15 10:24:41 INFO Uploading xx7mxs6r1jc3j1pds8x1azc6glsqjm2a-test-file.txt (152B)20482026/09/15 10:24:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20492026/09/15 10:24:41 INFO Uploading iha6cqvdzmsmab0mv8r8nyd2r6pyglld-test-script (136B)2050=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2051=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2052=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2053=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2054=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2055=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2056=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2057=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2058=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2059=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2060=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2061=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20622026/09/15 10:24:41 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]20632026/09/15 10:24:41 WARN Failed to register uploaded object key=9mbvf0q4gzvp0l344z66cadpk5njbzz7.narinfo error="server returned 404: 404 page not found\n"20642026/09/15 10:24:41 WARN Failed to register uploaded object key=43sgklw72id9a247fw9w02fp8x6n3zq1.narinfo error="server returned 404: 404 page not found\n"20652026/09/15 10:24:41 WARN Failed to register uploaded object key=4lz05fzz65zy3gdjbvy6d8y76py5ddff.narinfo error="server returned 404: 404 page not found\n"20662026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20672026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20682026/09/15 10:24:41 INFO OIDC auth successful provider=test scopes=[write]20692026/09/15 10:24:41 WARN Authentication failed token_preview=eyJhbGciOi...s06-bdLV7Q token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2070--- PASS: TestService_AuthMiddleware_OIDC (0.45s)2071 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2072 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2073 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2074 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20752026/09/15 10:24:41 WARN Failed to register uploaded object key=log/b2l970a2s2pymh3l7yr2gxwjhknyyvvq-test-script.drv error="server returned 404: 404 page not found\n"20762026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20772026/09/15 10:24:41 WARN Failed to register uploaded object key=xx7mxs6r1jc3j1pds8x1azc6glsqjm2a.ls error="server returned 404: 404 page not found\n"20782026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20792026/09/15 10:24:41 INFO Completed upload id=320802026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20812026/09/15 10:24:41 INFO Signed narinfos id=1 count=120822026/09/15 10:24:41 WARN Failed to register uploaded object key=iha6cqvdzmsmab0mv8r8nyd2r6pyglld.ls error="server returned 404: 404 page not found\n"20832026/09/15 10:24:41 INFO Uploading 1 narinfos20842026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2085=== NAME TestClientCADerivations2086 client_ca_test.go:139: Found 1 dependencies (including self)20872026/09/15 10:24:41 INFO Signed narinfos id=1 count=120882026/09/15 10:24:41 INFO Uploading 1 narinfos20892026/09/15 10:24:41 INFO Completed upload id=120902026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20912026/09/15 10:24:41 INFO Completed upload id=220922026/09/15 10:24:41 INFO Upload complete. (133ms)2093=== NAME TestClientMultipleUploads2094 client_integration_test.go:350: Uploaded 3 paths in 166.090511ms20952026/09/15 10:24:41 WARN Failed to register uploaded object key=xx7mxs6r1jc3j1pds8x1azc6glsqjm2a.narinfo error="server returned 404: 404 page not found\n"20962026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20972026/09/15 10:24:41 WARN Failed to register uploaded object key=iha6cqvdzmsmab0mv8r8nyd2r6pyglld.narinfo error="server returned 404: 404 page not found\n"20982026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20992026/09/15 10:24:41 WARN claim: cannot clear write deadline error="feature not supported"21002026/09/15 10:24:41 INFO Completed upload id=121012026/09/15 10:24:41 INFO Upload complete. (103ms)2102=== NAME TestClientIntegration2103 client_integration_test.go:293: Retrieved narinfo from S3:2104 StorePath: /build/TestClientIntegration4272763436/002/store/xx7mxs6r1jc3j1pds8x1azc6glsqjm2a-test-file.txt2105 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2106 Compression: zstd2107 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12108 NarSize: 1522109 References: 2110 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk121112026/09/15 10:24:41 INFO Completed upload id=121122026/09/15 10:24:41 INFO Upload complete. (64ms)2113--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.43s)2114--- PASS: TestClientMultipleUploads (0.79s)2115=== NAME TestClientWithDependencies2116 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2132968689/001/store) requires matching store prefix2117=== NAME TestClientIntegration2118 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)2119 client_integration_test.go:294: Decompressed .ls content (64 bytes):2120 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2121 client_integration_test.go:297: Testing garbage collection...2122--- PASS: TestClientWithDependencies (0.73s)2123--- PASS: TestService_ReadAuthMiddleware (0.44s)21242026/09/15 10:24:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures21252026/09/15 10:24:41 INFO Garbage collection started21262026/09/15 10:24:41 INFO Aborted multipart uploads count=021272026/09/15 10:24:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21282026/09/15 10:24:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.368288ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21292026/09/15 10:24:41 WARN Force mode enabled - objects will be deleted immediately without grace period21302026/09/15 10:24:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21312026/09/15 10:24:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21322026/09/15 10:24:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=NmRmZjU3M2MtYjg5Yi00NjA5LWE1YTEtNjZmOGQ5MTRkM2M4LjkzMjJlMmRhLTMzNzItNDEwYS04MWRjLWQ5NWM5ZWM4MzFkYngxNzg5NDY3ODgwNjMzMzA3NjU1 parts=1021332026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21342026/09/15 10:24:41 INFO Completed upload id=121352026/09/15 10:24:41 WARN claim: cannot clear write deadline error="feature not supported"21362026/09/15 10:24:41 WARN claim: cannot clear write deadline error="feature not supported"2137--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (1.00s)21382026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures21392026/09/15 10:24:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21402026/09/15 10:24:41 INFO Uploading 5r16y60s9wijdnn8drbzyimrj4bnz99a-unpinned-file.txt (128B)21412026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21422026/09/15 10:24:41 INFO Received uploads request method=POST path=/api/pending_closures21432026/09/15 10:24:41 WARN Failed to register uploaded object key=5r16y60s9wijdnn8drbzyimrj4bnz99a.ls error="server returned 404: 404 page not found\n"21442026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21452026/09/15 10:24:41 INFO Signed narinfos id=2 count=121462026/09/15 10:24:41 INFO Uploading 1 narinfos21472026/09/15 10:24:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21482026/09/15 10:24:41 INFO Uploading 0xczfhwddly0fqr249dgb7iyynyygs2c-ca-test (144B)21492026/09/15 10:24:41 WARN Failed to register uploaded object key=5r16y60s9wijdnn8drbzyimrj4bnz99a.narinfo error="server returned 404: 404 page not found\n"21502026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21512026/09/15 10:24:41 INFO Completed upload id=221522026/09/15 10:24:41 INFO Upload complete. (90ms)21532026/09/15 10:24:41 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21542026/09/15 10:24:41 WARN Failed to register uploaded object key=log/9sxw2mblwzc6hwkai75w1qvp500sbm9a-ca-test.drv error="server returned 404: 404 page not found\n"21552026/09/15 10:24:41 WARN Failed to register uploaded object key=0xczfhwddly0fqr249dgb7iyynyygs2c.ls error="server returned 404: 404 page not found\n"21562026/09/15 10:24:41 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21572026/09/15 10:24:41 INFO Signed narinfos id=1 count=121582026/09/15 10:24:41 INFO Uploading 1 narinfos21592026/09/15 10:24:41 WARN Failed to register uploaded object key=0xczfhwddly0fqr249dgb7iyynyygs2c.narinfo error="server returned 404: 404 page not found\n"21602026/09/15 10:24:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21612026/09/15 10:24:41 INFO Completed upload id=121622026/09/15 10:24:41 INFO Upload complete. (96ms)2163=== NAME TestClientCADerivations2164 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3189843515/001/store/0xczfhwddly0fqr249dgb7iyynyygs2c-ca-test2165 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2166 Compression: zstd2167 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2168 NarSize: 1442169 References: 2170 Deriver: /build/TestClientCADerivations3189843515/001/store/9sxw2mblwzc6hwkai75w1qvp500sbm9a-ca-test.drv2171 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2172 client_ca_test.go:185: Checking for realisation files in S3...2173 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2174 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21752026/09/15 10:24:41 INFO Received create pin request method=POST path=/api/pins/myapp21762026/09/15 10:24:41 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4248580417/001/store/kxq4plzdl1rmw3fxsnd78q591lxr4fgw-pinned-file.txt narinfo_key=kxq4plzdl1rmw3fxsnd78q591lxr4fgw.narinfo21772026/09/15 10:24:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures21782026/09/15 10:24:41 INFO Garbage collection started21792026/09/15 10:24:41 INFO Aborted multipart uploads count=021802026/09/15 10:24:41 WARN Force mode enabled - objects will be deleted immediately without grace period21812026/09/15 10:24:41 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21822026/09/15 10:24:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21832026/09/15 10:24:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.890282ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2184 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2185 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2186 error: binary cache 's3://bucket53?endpoint=http://localhost:40655®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3189843515/001/store'2187 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12188--- PASS: TestClientCADerivations (0.93s)2189--- PASS: TestClaim_StreamsThroughServer (2.21s)2190=== NAME TestOrphanedObjectsGCStressTest2191 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2192 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21932026/09/15 10:24:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=765.270953ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2194 orphaned_objects_gc_test.go:509: Stress test completed successfully:2195 orphaned_objects_gc_test.go:510: - Active objects preserved: 202196 orphaned_objects_gc_test.go:511: - Objects deleted: 2102197 orphaned_objects_gc_test.go:512: - Total GC'd: 2102198--- PASS: TestOrphanedObjectsGCStressTest (2.74s)21992026/09/15 10:24:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=022002026/09/15 10:24:42 INFO Vacuumed table table=pending_closures22012026/09/15 10:24:42 INFO Vacuumed table table=pending_objects22022026/09/15 10:24:42 INFO Vacuumed table table=multipart_uploads22032026/09/15 10:24:42 INFO Vacuumed table table=closures22042026/09/15 10:24:42 INFO Vacuumed table table=objects2205--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)2206 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.10s)2207 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.09s)2208 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.62s)22092026/09/15 10:24:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=022102026/09/15 10:24:42 INFO Vacuumed table table=pending_closures22112026/09/15 10:24:42 INFO Vacuumed table table=pending_objects22122026/09/15 10:24:42 INFO Vacuumed table table=multipart_uploads22132026/09/15 10:24:42 INFO Vacuumed table table=closures22142026/09/15 10:24:42 INFO Vacuumed table table=objects22152026/09/15 10:24:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.733722996s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2216--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.06s)22172026/09/15 10:24:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02218=== NAME TestClientIntegration2219 client_integration_test.go:304: Objects in database after GC:2220 client_integration_test.go:304: Successfully deleted all objects with GC --force2221--- PASS: TestClientIntegration (2.71s)22222026/09/15 10:24:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02223=== NAME TestPinProtectsFromGC2224 client_integration_test.go:711: Pin successfully protected closure from garbage collection2225--- PASS: TestPinProtectsFromGC (2.91s)22262026/09/15 10:24:44 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"22272026/09/15 10:24:44 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_closures22282026/09/15 10:24:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.375229ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22292026/09/15 10:24:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.499931ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/09/15 10:24:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=855.400735ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22312026/09/15 10:24:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.654898042s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/09/15 10:24:46 WARN Rate limiter enabled after throttle name=s3-test rate=522332026/09/15 10:24:46 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2234=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2235 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102236 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002237--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.95s)2238--- PASS: TestClientErrorHandling (0.00s)2239 --- PASS: TestClientErrorHandling/InvalidStorePath (0.33s)2240 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2241 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.59s)2242PASS22432026-09-15 10:24:47.800 UTC [129] LOG: received smart shutdown request22442026-09-15 10:24:47.805 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122452026-09-15 10:24:47.819 UTC [134] LOG: shutting down22462026-09-15 10:24:47.819 UTC [134] LOG: checkpoint starting: shutdown immediate22472026-09-15 10:24:49.011 UTC [134] LOG: checkpoint complete: wrote 10830 buffers (66.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 17 recycled; write=0.213 s, sync=0.967 s, total=1.192 s; sync files=21000, longest=0.002 s, average=0.001 s; distance=282890 kB, estimate=282890 kB; lsn=0/12BA8678, redo lsn=0/12BA867822482026-09-15 10:24:49.124 UTC [129] LOG: database system is shut down2249Running OIDC tests...2250=== RUN TestGlobMatch2251=== PAUSE TestGlobMatch2252=== RUN TestAudienceForIssuer2253=== PAUSE TestAudienceForIssuer2254=== RUN TestValidateToken_ValidToken2255=== PAUSE TestValidateToken_ValidToken2256=== RUN TestValidateToken_WrongAudience2257=== PAUSE TestValidateToken_WrongAudience2258=== RUN TestValidateToken_Expired2259=== PAUSE TestValidateToken_Expired2260=== RUN TestValidateToken_BoundClaimsMismatch2261=== PAUSE TestValidateToken_BoundClaimsMismatch2262=== RUN TestValidateToken_BoundSubjectMismatch2263=== PAUSE TestValidateToken_BoundSubjectMismatch2264=== RUN TestValidateToken_MultipleProviders2265=== PAUSE TestValidateToken_MultipleProviders2266=== RUN TestValidateToken_NoMatchingProvider2267=== PAUSE TestValidateToken_NoMatchingProvider2268=== RUN TestValidateToken_KubernetesServiceAccount2269=== PAUSE TestValidateToken_KubernetesServiceAccount2270=== RUN TestNewValidator_KubernetesRequiresCA2271=== PAUSE TestNewValidator_KubernetesRequiresCA2272=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2273=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2274=== RUN TestScopes_LegacyProviderDefaultsToWrite2275=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2276=== RUN TestScopes_Rules2277=== PAUSE TestScopes_Rules2278=== RUN TestScopes_ConfigValidation2279=== PAUSE TestScopes_ConfigValidation2280=== CONT TestGlobMatch2281=== CONT TestValidateToken_Expired2282=== RUN TestGlobMatch/foo_foo2283=== PAUSE TestGlobMatch/foo_foo2284=== RUN TestGlobMatch/foo_bar2285=== PAUSE TestGlobMatch/foo_bar2286=== CONT TestValidateToken_NoMatchingProvider2287=== CONT TestValidateToken_ValidToken2288=== RUN TestGlobMatch/*_2289=== PAUSE TestGlobMatch/*_2290=== CONT TestAudienceForIssuer2291--- PASS: TestAudienceForIssuer (0.00s)2292=== CONT TestScopes_LegacyProviderDefaultsToWrite2293=== CONT TestScopes_ConfigValidation2294=== CONT TestScopes_Rules2295=== CONT TestValidateToken_WrongAudience2296=== CONT TestNewValidator_KubernetesRequiresCA2297=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2298=== CONT TestValidateToken_KubernetesServiceAccount2299=== CONT TestValidateToken_BoundSubjectMismatch2300=== CONT TestValidateToken_MultipleProviders2301=== CONT TestValidateToken_BoundClaimsMismatch2302=== RUN TestGlobMatch/*_anything2303=== PAUSE TestGlobMatch/*_anything2304=== RUN TestGlobMatch/foo*_foo2305=== PAUSE TestGlobMatch/foo*_foo2306=== RUN TestGlobMatch/foo*_foobar2307=== PAUSE TestGlobMatch/foo*_foobar2308=== RUN TestGlobMatch/foo*_bar2309=== PAUSE TestGlobMatch/foo*_bar2310=== RUN TestGlobMatch/*bar_bar2311=== PAUSE TestGlobMatch/*bar_bar2312=== RUN TestGlobMatch/*bar_foobar2313=== PAUSE TestGlobMatch/*bar_foobar2314=== RUN TestGlobMatch/*bar_foo2315=== PAUSE TestGlobMatch/*bar_foo2316=== RUN TestGlobMatch/foo*bar_foobar2317=== PAUSE TestGlobMatch/foo*bar_foobar2318=== RUN TestGlobMatch/foo*bar_foo123bar2319=== PAUSE TestGlobMatch/foo*bar_foo123bar2320=== RUN TestGlobMatch/foo*bar_foobarbaz2321=== PAUSE TestGlobMatch/foo*bar_foobarbaz2322=== RUN TestGlobMatch/*/*_foo/bar2323=== PAUSE TestGlobMatch/*/*_foo/bar2324=== RUN TestGlobMatch/*/*_foo2325=== PAUSE TestGlobMatch/*/*_foo2326=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2327=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2328--- PASS: TestScopes_ConfigValidation (0.00s)2329=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.023302026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41947/oidc23312026/09/15 10:24:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43327/oidc23322026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36611/oidc23332026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38319/oidc23342026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38059/oidc2335=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.023362026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40989/oidc2337=== RUN TestGlobMatch/refs/*/main_refs/heads/main2338=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2339=== RUN TestGlobMatch/fo?_foo23402026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33539/oidc2341=== PAUSE TestGlobMatch/fo?_foo2342=== RUN TestGlobMatch/fo?_fo2343=== PAUSE TestGlobMatch/fo?_fo2344=== RUN TestGlobMatch/fo?_fooo23452026/09/15 10:24:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36019/oidc2346=== PAUSE TestGlobMatch/fo?_fooo2347=== RUN TestGlobMatch/?oo_foo2348=== PAUSE TestGlobMatch/?oo_foo2349=== RUN TestGlobMatch/?oo_boo2350=== PAUSE TestGlobMatch/?oo_boo2351=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2352=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2353=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2354=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2355=== CONT TestGlobMatch/foo_foo2356=== CONT TestGlobMatch/*/*_foo/bar2357=== CONT TestGlobMatch/foo*bar_foobarbaz2358=== CONT TestGlobMatch/foo_bar2359=== CONT TestGlobMatch/foo*bar_foo123bar2360=== CONT TestGlobMatch/?oo_boo2361=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main23622026/09/15 10:24:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38931/oidc2363=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main23642026/09/15 10:24:50 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232365=== CONT TestGlobMatch/fo?_fooo2366=== CONT TestGlobMatch/*bar_foo2367=== CONT TestGlobMatch/*bar_foobar2368=== CONT TestGlobMatch/fo?_foo2369=== CONT TestGlobMatch/*bar_bar2370=== CONT TestGlobMatch/foo*_bar2371=== CONT TestGlobMatch/*/*_foo2372=== CONT TestGlobMatch/foo*_foobar2373=== CONT TestGlobMatch/foo*_foo2374=== CONT TestGlobMatch/*_anything2375=== CONT TestGlobMatch/*_2376=== CONT TestGlobMatch/fo?_fo2377=== CONT TestGlobMatch/foo*bar_foobar2378=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02379=== CONT TestGlobMatch/?oo_foo2380=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2381=== CONT TestGlobMatch/refs/*/main_refs/heads/main2382--- PASS: TestGlobMatch (0.01s)2383 --- PASS: TestGlobMatch/foo_foo (0.00s)2384 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2385 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2386 --- PASS: TestGlobMatch/foo_bar (0.00s)2387 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2388 --- PASS: TestGlobMatch/?oo_boo (0.00s)2389 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2390 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2391 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2392 --- PASS: TestGlobMatch/*bar_foo (0.00s)2393 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2394 --- PASS: TestGlobMatch/fo?_foo (0.00s)2395 --- PASS: TestGlobMatch/foo*_bar (0.00s)2396 --- PASS: TestGlobMatch/*/*_foo (0.00s)2397 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2398 --- PASS: TestGlobMatch/foo*_foo (0.00s)2399 --- PASS: TestGlobMatch/*_anything (0.00s)2400 --- PASS: TestGlobMatch/*_ (0.00s)2401 --- PASS: TestGlobMatch/fo?_fo (0.00s)2402 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2403 --- PASS: TestGlobMatch/*bar_bar (0.00s)2404 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2405 --- PASS: TestGlobMatch/?oo_foo (0.00s)2406 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2407 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)24082026/09/15 10:24:50 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40039/oidc2409--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2410--- PASS: TestValidateToken_Expired (0.01s)2411--- PASS: TestValidateToken_ValidToken (0.01s)2412--- PASS: TestValidateToken_WrongAudience (0.01s)2413--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2414--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2415--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)24162026/09/15 10:24:50 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:399012417--- PASS: TestValidateToken_MultipleProviders (0.01s)2418--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)24192026/09/15 10:24:50 http: TLS handshake error from 127.0.0.1:56818: remote error: tls: bad certificate2420--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2421--- PASS: TestScopes_Rules (0.02s)2422--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)2423PASS2424Running hook tests...2425=== RUN TestSendPathsEmpty2426=== PAUSE TestSendPathsEmpty2427=== RUN TestQueueEnqueueAndFetch2428=== PAUSE TestQueueEnqueueAndFetch2429=== RUN TestQueueDeduplication2430=== PAUSE TestQueueDeduplication2431=== RUN TestQueueRemove2432=== PAUSE TestQueueRemove2433=== RUN TestQueueFetchBatchLimit2434=== PAUSE TestQueueFetchBatchLimit2435=== RUN TestQueueRetryMovesToBack2436=== PAUSE TestQueueRetryMovesToBack2437=== RUN TestQueueFetchRemoveLifecycle2438=== PAUSE TestQueueFetchRemoveLifecycle2439=== RUN TestQueueConcurrentWriters2440=== PAUSE TestQueueConcurrentWriters2441=== RUN TestQueueRemoveLargeClosure2442=== PAUSE TestQueueRemoveLargeClosure2443=== RUN TestServerClientIntegration2444=== PAUSE TestServerClientIntegration2445=== RUN TestServerQueueError2446=== PAUSE TestServerQueueError2447=== RUN TestGetListenerSocketActivation2448 server_test.go:210: === RUN TestGetListenerSocketActivation2449 --- PASS: TestGetListenerSocketActivation (0.00s)2450 PASS2451 2452--- PASS: TestGetListenerSocketActivation (0.01s)2453=== RUN TestDrainIsolatesPoisonPath2454=== PAUSE TestDrainIsolatesPoisonPath2455=== RUN TestRunNotBlockedByPoisonHead2456=== PAUSE TestRunNotBlockedByPoisonHead2457=== RUN TestDrainGivesUpWhenServerDown2458=== PAUSE TestDrainGivesUpWhenServerDown2459=== RUN TestFailedPathPrunedByLaterClosure2460=== PAUSE TestFailedPathPrunedByLaterClosure2461=== RUN TestWorkerUploadsAndRemoves2462=== PAUSE TestWorkerUploadsAndRemoves2463=== RUN TestWorkerSkipsGCdPaths2464=== PAUSE TestWorkerSkipsGCdPaths2465=== RUN TestWorkerPrunesClosureDeps2466=== PAUSE TestWorkerPrunesClosureDeps2467=== RUN TestDrainTimeout2468=== PAUSE TestDrainTimeout2469=== CONT TestSendPathsEmpty2470=== CONT TestWorkerUploadsAndRemoves2471=== CONT TestWorkerPrunesClosureDeps2472--- PASS: TestSendPathsEmpty (0.00s)2473=== CONT TestQueueConcurrentWriters2474=== CONT TestQueueFetchRemoveLifecycle2475=== CONT TestQueueRetryMovesToBack2476=== CONT TestQueueRemoveLargeClosure2477=== CONT TestQueueFetchBatchLimit2478=== CONT TestFailedPathPrunedByLaterClosure2479=== CONT TestQueueRemove2480=== CONT TestDrainGivesUpWhenServerDown2481=== CONT TestQueueDeduplication2482=== CONT TestRunNotBlockedByPoisonHead2483=== CONT TestQueueEnqueueAndFetch2484=== CONT TestDrainIsolatesPoisonPath2485=== CONT TestWorkerSkipsGCdPaths2486=== CONT TestServerQueueError2487=== CONT TestServerClientIntegration2488=== CONT TestDrainTimeout24892026/09/15 10:24:50 ERROR Failed to queue paths error="permission denied" count=12490--- PASS: TestServerQueueError (0.00s)2491--- PASS: TestServerClientIntegration (0.00s)24922026/09/15 10:24:50 INFO Upload queue status pending=324932026/09/15 10:24:50 INFO Uploading batch count=124942026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=124952026/09/15 10:24:50 INFO Uploading batch count=224962026/09/15 10:24:50 INFO Uploading batch count=424972026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=424982026/09/15 10:24:50 INFO Uploading batch count=124992026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=125002026/09/15 10:24:50 INFO Upload queue status pending=225012026/09/15 10:24:50 INFO Uploading batch count=225022026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=225032026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677047186/002/a25042026/09/15 10:24:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3813066688/002/nonexistent25052026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2688180135/002/bbb25062026/09/15 10:24:50 INFO Uploading batch count=125072026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677047186/002/b25082026/09/15 10:24:50 INFO Uploading batch count=125092026/09/15 10:24:50 INFO Upload queue status pending=22510--- PASS: TestQueueEnqueueAndFetch (0.01s)25112026/09/15 10:24:50 INFO Upload queue status pending=22512--- PASS: TestQueueFetchBatchLimit (0.01s)25132026/09/15 10:24:50 INFO Uploading batch count=22514--- PASS: TestQueueDeduplication (0.01s)25152026/09/15 10:24:50 INFO Uploading batch count=125162026/09/15 10:24:50 INFO Uploading batch count=225172026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=225182026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677047186/002/c25192026/09/15 10:24:50 INFO Uploading batch count=12520--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25212026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677047186/002/d2522--- PASS: TestQueueRemove (0.02s)2523--- PASS: TestQueueRetryMovesToBack (0.02s)25242026/09/15 10:24:50 INFO Uploading batch count=125252026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=125262026/09/15 10:24:50 INFO Uploading batch count=225272026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=225282026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677047186/002/e25292026/09/15 10:24:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677047186/002/f25302026/09/15 10:24:50 INFO Uploading batch count=125312026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=125322026/09/15 10:24:50 ERROR Drain finished with paths left in queue remaining=102533--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25342026/09/15 10:24:50 INFO Uploading batch count=125352026/09/15 10:24:50 ERROR Upload failed error="upload failed" count=125362026/09/15 10:24:50 ERROR Drain finished with paths left in queue remaining=12537--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2538--- PASS: TestDrainIsolatesPoisonPath (0.02s)2539--- PASS: TestWorkerSkipsGCdPaths (0.03s)2540--- PASS: TestWorkerUploadsAndRemoves (0.04s)2541--- PASS: TestWorkerPrunesClosureDeps (0.04s)25422026/09/15 10:24:50 ERROR Upload failed error="context deadline exceeded" count=225432026/09/15 10:24:50 ERROR Drain finished with paths left in queue remaining=42544--- PASS: TestDrainTimeout (0.21s)2545--- PASS: TestQueueConcurrentWriters (0.22s)2546--- PASS: TestQueueRemoveLargeClosure (0.23s)25472026/09/15 10:24:51 INFO Uploading batch count=125482026/09/15 10:24:51 INFO Uploading batch count=125492026/09/15 10:24:51 INFO Uploading batch count=125502026/09/15 10:24:51 ERROR Upload failed error="upload failed" count=125512026/09/15 10:24:51 INFO Uploading batch count=125522026/09/15 10:24:51 ERROR Upload failed error="upload failed" count=125532026/09/15 10:24:51 INFO Uploading batch count=125542026/09/15 10:24:51 ERROR Upload failed error="upload failed" count=125552026/09/15 10:24:51 INFO Uploading batch count=125562026/09/15 10:24:51 ERROR Upload failed error="upload failed" count=125572026/09/15 10:24:51 ERROR Drain finished with paths left in queue remaining=12558--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2559PASS