niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #182
· 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 TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestScriptTokenNoExpiryRerunsEveryCall75=== CONT TestSetClientTLSDoesNotMutateDefaultTransport76=== CONT TestPathInfoHashCompatibility77=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)78=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)79=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon80=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon81=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI82=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI83=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha51284=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha51285=== CONT TestFileTokenReadsAndCaches86=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)87=== CONT TestSetClientTLS88=== CONT TestShellSplitErrors89--- PASS: TestShellSplitErrors (0.00s)90=== CONT TestScriptTokenBadJSON91=== CONT TestScriptTokenEmptyCommand92--- PASS: TestScriptTokenEmptyCommand (0.00s)93=== CONT TestScriptTokenScriptFails94=== CONT TestShellSplit95=== CONT TestSetClientTLSErrors96=== CONT TestDoWithRetry_BodyReplayedViaGetBody97=== CONT TestResolveStorePath98=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess99=== CONT TestRateLimiterFeedback100=== RUN TestRateLimiterFeedback/429_enables_limiter101=== PAUSE TestRateLimiterFeedback/429_enables_limiter102=== RUN TestRateLimiterFeedback/503_enables_limiter103=== CONT TestPathInfoCACompatibility104=== CONT TestParsePathInfoJSONMultiplePaths105=== CONT TestParsePathInfoJSON106=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512107=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1082026/09/07 19:37:09 WARN Rate limiter enabled after throttle name=server-test rate=5109=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon110=== CONT TestDumpPathSingleFile111=== CONT TestGetStorePathHash112=== CONT TestConvertHashToNix32113=== CONT TestEncodeNixBase32WithRealHash114=== CONT TestEncodeNixBase32115=== CONT TestDumpPathWriterError116--- PASS: TestFileTokenReadsAndCaches (0.00s)117=== CONT TestFileTokenEmpty118=== CONT TestFileTokenMissing119--- PASS: TestShellSplit (0.00s)120--- PASS: TestResolveStorePath (0.00s)121=== CONT TestPartSizeForNAR122--- PASS: TestScriptTokenScriptFails (0.00s)123=== CONT TestDumpPathMatchesNix124=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== RUN TestPathInfoCACompatibility/null_ca_field126=== RUN TestGetStorePathHash/valid_store_path127=== RUN TestSetClientTLSErrors/missing_cert_file128--- PASS: TestScriptTokenBadJSON (0.00s)129=== PAUSE TestRateLimiterFeedback/503_enables_limiter130=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter131=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter132=== RUN TestEncodeNixBase32/test_string_hash133=== PAUSE TestEncodeNixBase32/test_string_hash134=== RUN TestEncodeNixBase32/empty_input135=== PAUSE TestEncodeNixBase32/empty_input136=== CONT TestScriptTokenEmptyToken137=== CONT TestCaseHackSuffix138=== RUN TestParsePathInfoJSON/Nix_format139=== PAUSE TestParsePathInfoJSON/Nix_format140=== PAUSE TestPathInfoCACompatibility/null_ca_field141=== CONT TestStaticToken1422026/09/07 19:37:09 WARN Rate limiter enabled after throttle name=server-test rate=5143=== CONT TestEncodeNixBase32/test_string_hash1442026/09/07 19:37:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43391145=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths146=== CONT TestScriptTokenCachesUntilRefresh147--- PASS: TestFileTokenEmpty (0.00s)148--- PASS: TestEncodeNixBase32WithRealHash (0.00s)149=== RUN TestParsePathInfoJSON/Lix_format150=== PAUSE TestParsePathInfoJSON/Lix_format151=== RUN TestParsePathInfoJSON/empty_input152=== RUN TestConvertHashToNix32/SRI_format_to_Nix32153=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32154=== RUN TestConvertHashToNix32/already_Nix32_format155=== PAUSE TestConvertHashToNix32/already_Nix32_format156=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter157=== PAUSE TestSetClientTLSErrors/missing_cert_file158=== CONT TestFilterOversizedClosures159=== CONT TestUploadMultipart_SupersededByPeer160=== RUN TestPartSizeForNAR/zero_stays_at_minimum161=== PAUSE TestGetStorePathHash/valid_store_path1622026/09/07 19:37:09 WARN Rate limiter backed off name=server-test rate=5163=== RUN TestPathInfoCACompatibility/old_string_format_-_text164=== CONT TestEncodeNixBase32/empty_input1652026/09/07 19:37:09 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43391166=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths167=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text168=== PAUSE TestParsePathInfoJSON/empty_input169=== RUN TestFilterOversizedClosures/no_limit_keeps_everything170=== RUN TestConvertHashToNix32/invalid_format171=== RUN TestSetClientTLSErrors/missing_key_file172=== RUN TestSetClientTLS/rejects_connection_without_client_cert173=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum174=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter175--- PASS: TestPathInfoHashCompatibility (0.00s)176 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)177 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)178 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)179 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)180=== RUN TestGetStorePathHash/basename_without_hyphen_should_error181=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths182=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== RUN TestUploadMultipart_SupersededByPeer/exists184=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths185=== PAUSE TestConvertHashToNix32/invalid_format186=== RUN TestParsePathInfoJSON/whitespace_only187=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything188=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert189=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive190=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped191=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped192=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA193=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter194=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter195=== CONT TestRateLimiterFeedback/429_enables_limiter196=== CONT TestRateLimiterFeedback/503_enables_limiter197=== PAUSE TestSetClientTLSErrors/missing_key_file198--- PASS: TestStaticToken (0.00s)199=== PAUSE TestUploadMultipart_SupersededByPeer/exists200--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)201--- PASS: TestFileTokenMissing (0.00s)202--- PASS: TestDoServerRequestAttachesToken (0.01s)203--- PASS: TestScriptTokenEmptyToken (0.01s)204=== RUN TestPartSizeForNAR/small_stays_at_minimum205=== CONT TestConvertHashToNix32/invalid_format206--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)207--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)208=== CONT TestConvertHashToNix32/already_Nix32_format209=== CONT TestConvertHashToNix32/SRI_format_to_Nix32210=== RUN TestFilterOversizedClosures/all_closures_skipped211=== PAUSE TestFilterOversizedClosures/all_closures_skipped212=== CONT TestFilterOversizedClosures/no_limit_keeps_everything213=== CONT TestFilterOversizedClosures/all_closures_skipped2142026/09/07 19:37:09 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=50215=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive216=== RUN TestPathInfoCACompatibility/new_structured_format_-_text217=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text218=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method219=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method220=== CONT TestPathInfoCACompatibility/null_ca_field221=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive222=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2232026/09/07 19:37:09 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=2000224=== CONT TestPathInfoCACompatibility/old_string_format_-_text225--- PASS: TestFilterOversizedClosures (0.00s)226 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)227 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)228 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)229=== CONT TestPathInfoCACompatibility/new_structured_format_-_text230=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method231--- PASS: TestPathInfoCACompatibility (0.01s)232 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)233 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)234 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)235 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)236 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)237=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA238=== PAUSE TestParsePathInfoJSON/whitespace_only239=== RUN TestSetClientTLS/preserves_debug_logging_transport240=== PAUSE TestSetClientTLS/preserves_debug_logging_transport241=== CONT TestSetClientTLS/rejects_connection_without_client_cert242=== CONT TestSetClientTLS/preserves_debug_logging_transport243=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA244=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error245=== RUN TestSetClientTLSErrors/missing_ca_file246=== RUN TestUploadMultipart_SupersededByPeer/missing247=== PAUSE TestPartSizeForNAR/small_stays_at_minimum248--- PASS: TestEncodeNixBase32 (0.01s)249 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)250 --- PASS: TestEncodeNixBase32/empty_input (0.00s)251--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)252 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)253 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)254=== RUN TestParsePathInfoJSON/invalid_JSON255=== PAUSE TestParsePathInfoJSON/invalid_JSON256=== CONT TestParsePathInfoJSON/Nix_format257=== CONT TestParsePathInfoJSON/whitespace_only258=== CONT TestParsePathInfoJSON/empty_input2592026/09/07 19:37:09 WARN Rate limiter enabled after throttle name=server-test rate=5260=== PAUSE TestSetClientTLSErrors/missing_ca_file2612026/09/07 19:37:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:46419262=== RUN TestSetClientTLSErrors/invalid_ca_file263=== PAUSE TestUploadMultipart_SupersededByPeer/missing2642026/09/07 19:37:09 WARN Rate limiter backed off name=server-test rate=5265=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum266=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum267=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts268=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts269=== RUN TestPartSizeForNAR/1_TiB2702026/09/07 19:37:09 WARN Rate limiter enabled after throttle name=server-test rate=5271--- PASS: TestConvertHashToNix32 (0.01s)272 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)273 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)274 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)2752026/09/07 19:37:09 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43525276=== CONT TestParsePathInfoJSON/Lix_format277=== CONT TestParsePathInfoJSON/invalid_JSON278=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error2792026/09/07 19:37:09 WARN Rate limiter backed off name=server-test rate=5280=== PAUSE TestSetClientTLSErrors/invalid_ca_file281=== CONT TestSetClientTLSErrors/missing_cert_file282=== CONT TestUploadMultipart_SupersededByPeer/exists283=== CONT TestUploadMultipart_SupersededByPeer/missing284=== PAUSE TestPartSizeForNAR/1_TiB285=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error286=== RUN TestPartSizeForNAR/5_TiB_S3_max_object287=== CONT TestSetClientTLSErrors/missing_ca_file288=== CONT TestSetClientTLSErrors/missing_key_file289--- PASS: TestParsePathInfoJSON (0.02s)290 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)291 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)292 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)293 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)294 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)295=== CONT TestSetClientTLSErrors/invalid_ca_file296--- PASS: TestRateLimiterFeedback (0.01s)297 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)298 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)299 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)300 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error303=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error304=== CONT TestGetStorePathHash/valid_store_path305--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)306=== CONT TestGetStorePathHash/basename_without_hyphen_should_error307=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error308=== RUN TestPartSizeForNAR/capped_at_5_GiB309=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error310=== PAUSE TestPartSizeForNAR/capped_at_5_GiB311=== CONT TestPartSizeForNAR/zero_stays_at_minimum312=== CONT TestPartSizeForNAR/capped_at_5_GiB313=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum314=== CONT TestPartSizeForNAR/1_TiB315--- PASS: TestGetStorePathHash (0.03s)316 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)317 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)318 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)319 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)320=== CONT TestPartSizeForNAR/5_TiB_S3_max_object321=== CONT TestPartSizeForNAR/small_stays_at_minimum322=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts323--- PASS: TestPartSizeForNAR (0.03s)324 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)325 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)326 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)328 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)329 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)330 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)331--- PASS: TestSetClientTLSErrors (0.03s)332 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)335 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)336--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)337 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)338 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)339--- PASS: TestDumpPathSingleFile (0.03s)3402026/09/07 19:37:09 http: TLS handshake error from 127.0.0.1:58024: remote error: tls: bad certificate341--- PASS: TestSetClientTLS (0.02s)342 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)343 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)344 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)345--- PASS: TestCaseHackSuffix (0.04s)346--- PASS: TestDumpPathWriterError (0.05s)347--- PASS: TestDumpPathMatchesNix (0.12s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres2081648062/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: 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.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres2081648062/data -l logfile start377378/build/postgres2081648062:5432 - no response3792026-09-07 19:37:11.031 UTC [109] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-09-07 19:37:11.031 UTC [109] LOG: listening on Unix socket "/build/postgres2081648062/.s.PGSQL.5432"3812026-09-07 19:37:11.036 UTC [116] LOG: database system was shut down at 2026-09-07 19:37:10 UTC3822026-09-07 19:37:11.040 UTC [109] LOG: database system is ready to accept connections383/build/postgres2081648062:5432 - accepting connections384=== RUN TestService_AuthMiddleware385=== PAUSE TestService_AuthMiddleware386=== RUN TestService_AuthMiddleware_MTLSProxyHeader387=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader388=== RUN TestService_AuthMiddleware_MTLSBoundSubjects389=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects390=== RUN TestService_ReadAuthMiddleware391=== PAUSE TestService_ReadAuthMiddleware392=== RUN TestService_AuthMiddleware_OIDC393=== PAUSE TestService_AuthMiddleware_OIDC394=== RUN TestService_RequireScope_OIDC395=== PAUSE TestService_RequireScope_OIDC396=== RUN TestService_ReadScope_PublicByDefault397=== PAUSE TestService_ReadScope_PublicByDefault398=== RUN TestCacheConfigHandler399=== PAUSE TestCacheConfigHandler400=== RUN TestCacheStatsHandler401=== PAUSE TestCacheStatsHandler402=== RUN TestClaim_BuildWaitComplete403=== PAUSE TestClaim_BuildWaitComplete404=== RUN TestClaim_GCMarkedOutputCountsAsAbsent405=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent406=== RUN TestClaim_TooManyStreams407=== PAUSE TestClaim_TooManyStreams408=== RUN TestClaim_HolderDisconnectKeepsClaim409=== PAUSE TestClaim_HolderDisconnectKeepsClaim410=== RUN TestClaim_FailWakesWaitersButIsNotRemembered411=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered412=== RUN TestClaim_FailWithoutKindReleases413=== PAUSE TestClaim_FailWithoutKindReleases414=== RUN TestClaim_StaleHeartbeatStolen415=== PAUSE TestClaim_StaleHeartbeatStolen416=== RUN TestClaim_TwoInstances417=== PAUSE TestClaim_TwoInstances418=== RUN TestClaim_InputsTouched419=== PAUSE TestClaim_InputsTouched420=== RUN TestClaim_StreamsThroughServer421=== PAUSE TestClaim_StreamsThroughServer422=== RUN TestClientCADerivations423=== PAUSE TestClientCADerivations424=== RUN TestClientErrorHandling425=== PAUSE TestClientErrorHandling426=== RUN TestClientIntegration427=== PAUSE TestClientIntegration428=== RUN TestClientMultipleUploads429=== PAUSE TestClientMultipleUploads430=== RUN TestClientWithDependencies431=== PAUSE TestClientWithDependencies432=== RUN TestPinProtectsFromGC433=== PAUSE TestPinProtectsFromGC434=== RUN TestResolveDBConnectionString435=== PAUSE TestResolveDBConnectionString436=== RUN TestGCAdvisoryLockBlocksConcurrentRun4372026-09-07 19:37:13.502 UTC [519] ERROR: relation "goose_db_version" does not exist at character 364382026-09-07 19:37:13.502 UTC [519] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4392026/09/07 19:37:13 OK 20241026095416_initial_model.sql (11.94ms)4402026/09/07 19:37:13 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)4412026/09/07 19:37:13 OK 20251218171726_add_pins.sql (3.26ms)4422026/09/07 19:37:13 OK 20260628120000_add_object_size_and_stats.sql (2.62ms)4432026/09/07 19:37:13 OK 20260905000000_add_claims.sql (3.34ms)4442026/09/07 19:37:13 goose: successfully migrated database to version: 202609050000004452026/09/07 19:37:13 OK 1_commit_pending_closure.sql (1.92ms)4462026/09/07 19:37:13 OK 2_object_stats_trigger.sql (810.35µs)4472026/09/07 19:37:13 goose: up to current file version: 2448--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.91s)449=== RUN TestGCBugBareHashReferences450=== PAUSE TestGCBugBareHashReferences451=== RUN TestGCMetrics452=== PAUSE TestGCMetrics453=== RUN TestGCTaskStore_StartNew454=== PAUSE TestGCTaskStore_StartNew455=== RUN TestGCTaskStore_DeduplicateSameParams456=== PAUSE TestGCTaskStore_DeduplicateSameParams457=== RUN TestGCTaskStore_ConflictDifferentParams458=== PAUSE TestGCTaskStore_ConflictDifferentParams459=== RUN TestGCTaskStore_GetEmpty460=== PAUSE TestGCTaskStore_GetEmpty461=== RUN TestGCTaskStore_GetReturnsLatest462=== PAUSE TestGCTaskStore_GetReturnsLatest463=== RUN TestGCTaskStore_CompletedAllowsNewTask464=== PAUSE TestGCTaskStore_CompletedAllowsNewTask465=== RUN TestGCTaskStore_PhaseUpdates466=== PAUSE TestGCTaskStore_PhaseUpdates467=== RUN TestGCTaskStore_Fail468=== PAUSE TestGCTaskStore_Fail469=== RUN TestGracefulShutdownDrainsInflight470=== PAUSE TestGracefulShutdownDrainsInflight471=== RUN TestService_healthCheckHandler472=== PAUSE TestService_healthCheckHandler473=== RUN TestService_readinessHandler474=== PAUSE TestService_readinessHandler475=== RUN TestGenerateLandingPage476=== PAUSE TestGenerateLandingPage477=== RUN TestCacheConfigHandlerMaxNarSize478=== PAUSE TestCacheConfigHandlerMaxNarSize479=== RUN TestCreatePendingClosureRejectsOversizedNAR480=== PAUSE TestCreatePendingClosureRejectsOversizedNAR481=== RUN TestNARDeduplicationMetadataUploadBug482=== PAUSE TestNARDeduplicationMetadataUploadBug483=== RUN TestMetricsInventory484=== PAUSE TestMetricsInventory485=== RUN TestService_NativeMTLS486=== PAUSE TestService_NativeMTLS487=== RUN TestServerTLSConfig488=== PAUSE TestServerTLSConfig489=== RUN TestMultipartCleanup490=== PAUSE TestMultipartCleanup491=== RUN TestObjectStatsTrigger492=== PAUSE TestObjectStatsTrigger493=== RUN TestOrphanedObjectsGC494=== PAUSE TestOrphanedObjectsGC495=== RUN TestOrphanedObjectsGCStressTest496=== PAUSE TestOrphanedObjectsGCStressTest497=== RUN TestResurrectedObjectNotDeleted498=== PAUSE TestResurrectedObjectNotDeleted499=== RUN TestParseSingleRange500=== PAUSE TestParseSingleRange501=== RUN TestIsValidCachePath502=== PAUSE TestIsValidCachePath503=== RUN TestReadProxyNarinfo504=== PAUSE TestReadProxyNarinfo505=== RUN TestReadProxyNarinfoAlreadyDecompressed506=== PAUSE TestReadProxyNarinfoAlreadyDecompressed507=== RUN TestReadProxyNarStreaming508=== PAUSE TestReadProxyNarStreaming509=== RUN TestReadProxy404510=== PAUSE TestReadProxy404511=== RUN TestReadProxyInvalidPath512=== PAUSE TestReadProxyInvalidPath513=== RUN TestReadProxyHead514=== PAUSE TestReadProxyHead515=== RUN TestReadProxyConditionalGet516=== PAUSE TestReadProxyConditionalGet517=== RUN TestReadProxyRootRedirectsToIndexHTML518=== PAUSE TestReadProxyRootRedirectsToIndexHTML519=== RUN TestReadProxyDisabled520=== PAUSE TestReadProxyDisabled521=== RUN TestReadRedirectNar522=== PAUSE TestReadRedirectNar523=== RUN TestReadRedirectKeepsNarinfoProxied524=== PAUSE TestReadRedirectKeepsNarinfoProxied525=== RUN TestReadProxyRangeRequest526=== PAUSE TestReadProxyRangeRequest527=== RUN TestReadRedirectUsesPublicS3URL528=== PAUSE TestReadRedirectUsesPublicS3URL529=== RUN TestRedundantMultipartUpload530=== PAUSE TestRedundantMultipartUpload531=== RUN TestCompleteMultipartUpload_ErrorButObjectExists532=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists533=== RUN TestCompletedNarNotReofferedAcrossClosures534=== PAUSE TestCompletedNarNotReofferedAcrossClosures535=== RUN TestPresignedUploadRegisteredBeforeCommit536=== PAUSE TestPresignedUploadRegisteredBeforeCommit537=== RUN TestService_Rustfstest538=== PAUSE TestService_Rustfstest539=== RUN TestParseSize540=== PAUSE TestParseSize541=== RUN TestSkippedUploadsHandler542=== PAUSE TestSkippedUploadsHandler543=== RUN TestSystemdListenerNotActivated544--- PASS: TestSystemdListenerNotActivated (0.00s)545=== RUN TestWatchdogBeatsWhenHealthy546--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)547=== RUN TestWatchdogSkipsWhenUnhealthy5482026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5492026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5502026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5512026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5522026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5532026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5542026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5552026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5562026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5572026/09/07 19:37:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"558--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)559=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle560=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle561=== RUN TestProxyWriteTimeout562=== PAUSE TestProxyWriteTimeout563=== RUN TestIsValidUploadKey564=== PAUSE TestIsValidUploadKey565=== RUN TestUploadHandlersRejectInvalidKeys566=== PAUSE TestUploadHandlersRejectInvalidKeys567=== RUN TestUploadHandlersRejectOversizedBody568=== PAUSE TestUploadHandlersRejectOversizedBody569=== RUN TestService_cleanupPendingClosuresHandler570=== PAUSE TestService_cleanupPendingClosuresHandler571=== RUN TestService_createPendingClosureHandler572=== PAUSE TestService_createPendingClosureHandler573=== RUN TestService_verifyS3Integrity574=== PAUSE TestService_verifyS3Integrity575=== RUN TestCompleteMultipartUnregistered576=== PAUSE TestCompleteMultipartUnregistered577=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT578=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT579=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT580=== CONT TestService_AuthMiddleware581=== CONT TestCompleteMultipartUnregistered582=== CONT TestService_verifyS3Integrity583=== CONT TestService_createPendingClosureHandler584=== CONT TestService_cleanupPendingClosuresHandler585=== CONT TestUploadHandlersRejectOversizedBody586=== CONT TestUploadHandlersRejectInvalidKeys587=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info588=== CONT TestIsValidUploadKey589=== RUN TestIsValidUploadKey/narinfo590=== CONT TestProxyWriteTimeout591=== RUN TestProxyWriteTimeout/narinfo592=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle593=== CONT TestSkippedUploadsHandler594=== CONT TestGCTaskStore_Fail595--- PASS: TestGCTaskStore_Fail (0.00s)596=== CONT TestGCTaskStore_PhaseUpdates597=== CONT TestGCTaskStore_CompletedAllowsNewTask598=== CONT TestGCTaskStore_GetReturnsLatest599=== CONT TestGCTaskStore_GetEmpty600=== CONT TestGCTaskStore_ConflictDifferentParams601=== CONT TestGracefulShutdownDrainsInflight602=== CONT TestParseSize603=== CONT TestGCTaskStore_DeduplicateSameParams604=== CONT TestGCTaskStore_StartNew605=== CONT TestService_Rustfstest606=== CONT TestGCMetrics607=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info608=== PAUSE TestIsValidUploadKey/narinfo609=== PAUSE TestProxyWriteTimeout/narinfo610=== CONT TestPresignedUploadRegisteredBeforeCommit611--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)612--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)613--- PASS: TestGCTaskStore_GetEmpty (0.00s)614--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)615--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)616--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)617--- PASS: TestParseSize (0.00s)618=== CONT TestGCBugBareHashReferences6192026/09/07 19:37:14 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000620=== CONT TestCompletedNarNotReofferedAcrossClosures621=== CONT TestResolveDBConnectionString622=== CONT TestPinProtectsFromGC623=== CONT TestCompleteMultipartUpload_ErrorButObjectExists624=== RUN TestIsValidUploadKey/nar_zst625=== PAUSE TestIsValidUploadKey/nar_zst626=== RUN TestIsValidUploadKey/nar_xz627=== PAUSE TestIsValidUploadKey/nar_xz628=== RUN TestIsValidUploadKey/nar_plain629=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal630=== RUN TestProxyWriteTimeout/1_GiB_nar631=== RUN TestResolveDBConnectionString/flag_wins632=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal633=== PAUSE TestProxyWriteTimeout/1_GiB_nar634=== PAUSE TestIsValidUploadKey/nar_plain635=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key636=== RUN TestIsValidUploadKey/listing637=== RUN TestProxyWriteTimeout/10_GiB_nar638--- PASS: TestSkippedUploadsHandler (0.01s)639=== CONT TestReadRedirectUsesPublicS3URL640=== CONT TestRedundantMultipartUpload641--- PASS: TestGCTaskStore_StartNew (0.00s)642=== PAUSE TestResolveDBConnectionString/flag_wins643=== CONT TestClientWithDependencies644=== RUN TestResolveDBConnectionString/file_when_flag_empty645=== PAUSE TestResolveDBConnectionString/file_when_flag_empty646=== RUN TestResolveDBConnectionString/missing_file_is_an_error647=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error648=== RUN TestResolveDBConnectionString/PGHOST_allows_empty649=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty650=== CONT TestClientMultipleUploads651=== PAUSE TestIsValidUploadKey/listing652=== RUN TestIsValidUploadKey/build_log653=== PAUSE TestIsValidUploadKey/build_log654=== RUN TestIsValidUploadKey/build_log_home-manager_file655=== PAUSE TestIsValidUploadKey/build_log_home-manager_file656=== RUN TestIsValidUploadKey/build_log_plus_in_name657=== PAUSE TestIsValidUploadKey/build_log_plus_in_name658=== RUN TestIsValidUploadKey/build_log_question_mark659=== PAUSE TestIsValidUploadKey/build_log_question_mark660=== RUN TestIsValidUploadKey/build_log_equals661=== RUN TestResolveDBConnectionString/nothing_configured6622026/09/07 19:37:14 INFO Starting HTTP server address=127.0.0.1:46499663=== PAUSE TestResolveDBConnectionString/nothing_configured664=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key665=== CONT TestReadProxyRangeRequest666=== PAUSE TestProxyWriteTimeout/10_GiB_nar667=== RUN TestProxyWriteTimeout/unknown_size668=== PAUSE TestProxyWriteTimeout/unknown_size669=== PAUSE TestIsValidUploadKey/build_log_equals670=== RUN TestIsValidUploadKey/realisation671=== PAUSE TestIsValidUploadKey/realisation672=== RUN TestIsValidUploadKey/realisation_plus_in_output673=== PAUSE TestIsValidUploadKey/realisation_plus_in_output674=== CONT TestClientIntegration675=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key676=== RUN TestIsValidUploadKey/nix-cache-info677=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key6782026/09/07 19:37:14 INFO Shutdown signal received, draining in-flight requests timeout=10s679=== PAUSE TestIsValidUploadKey/nix-cache-info680=== RUN TestIsValidUploadKey/index.html681=== PAUSE TestIsValidUploadKey/index.html682=== RUN TestIsValidUploadKey/narinfo_key,_nar_type683=== CONT TestReadRedirectKeepsNarinfoProxied684=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type685=== RUN TestIsValidUploadKey/nar_key,_narinfo_type686=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type687=== RUN TestIsValidUploadKey/listing_key,_narinfo_type688=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type689=== RUN TestIsValidUploadKey/traversal690=== PAUSE TestIsValidUploadKey/traversal691=== RUN TestIsValidUploadKey/traversal_nar692=== PAUSE TestIsValidUploadKey/traversal_nar693=== RUN TestIsValidUploadKey/absolute694=== PAUSE TestIsValidUploadKey/absolute695=== RUN TestIsValidUploadKey/empty_key696=== PAUSE TestIsValidUploadKey/empty_key697=== RUN TestIsValidUploadKey/unknown_type698=== PAUSE TestIsValidUploadKey/unknown_type699=== CONT TestClientErrorHandling700=== RUN TestClientErrorHandling/InvalidStorePath701=== PAUSE TestClientErrorHandling/InvalidStorePath702=== RUN TestClientErrorHandling/InvalidAuthToken703=== PAUSE TestClientErrorHandling/InvalidAuthToken704=== RUN TestClientErrorHandling/ServerNotAvailable705=== PAUSE TestClientErrorHandling/ServerNotAvailable706=== CONT TestReadRedirectNar7072026-09-07 19:37:14.686 UTC [588] ERROR: relation "goose_db_version" does not exist at character 367082026-09-07 19:37:14.686 UTC [588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC709--- PASS: TestGracefulShutdownDrainsInflight (0.13s)710=== CONT TestClaim_BuildWaitComplete7112026-09-07 19:37:14.687 UTC [587] ERROR: relation "goose_db_version" does not exist at character 367122026-09-07 19:37:14.687 UTC [587] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-07 19:37:14.694 UTC [589] ERROR: relation "goose_db_version" does not exist at character 367142026-09-07 19:37:14.694 UTC [589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC715=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure716=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure717=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart718=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart719=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts720=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts721=== CONT TestReadProxyDisabled7222026-09-07 19:37:14.747 UTC [597] ERROR: relation "goose_db_version" does not exist at character 367232026-09-07 19:37:14.747 UTC [597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-07 19:37:14.781 UTC [599] ERROR: relation "goose_db_version" does not exist at character 367252026-09-07 19:37:14.781 UTC [599] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026/09/07 19:37:14 OK 20241026095416_initial_model.sql (51.82ms)7272026/09/07 19:37:14 OK 20241026095416_initial_model.sql (25.75ms)7282026/09/07 19:37:14 OK 20241026095416_initial_model.sql (70.57ms)7292026/09/07 19:37:14 OK 20241026095416_initial_model.sql (71.98ms)7302026-09-07 19:37:14.800 UTC [601] ERROR: relation "goose_db_version" does not exist at character 367312026-09-07 19:37:14.800 UTC [601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.09ms)7332026-09-07 19:37:14.800 UTC [600] ERROR: relation "goose_db_version" does not exist at character 367342026-09-07 19:37:14.800 UTC [600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7352026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (5.13ms)7362026-09-07 19:37:14.806 UTC [602] ERROR: relation "goose_db_version" does not exist at character 367372026-09-07 19:37:14.806 UTC [602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (6.51ms)7392026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (7.53ms)7402026-09-07 19:37:14.807 UTC [603] ERROR: relation "goose_db_version" does not exist at character 367412026-09-07 19:37:14.807 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/09/07 19:37:14 OK 20251218171726_add_pins.sql (10.45ms)7432026/09/07 19:37:14 OK 20251218171726_add_pins.sql (7.61ms)7442026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.19ms)7452026/09/07 19:37:14 OK 20251218171726_add_pins.sql (8.67ms)7462026/09/07 19:37:14 OK 20241026095416_initial_model.sql (14.77ms)7472026-09-07 19:37:14.820 UTC [604] ERROR: relation "goose_db_version" does not exist at character 367482026-09-07 19:37:14.820 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7492026-09-07 19:37:14.824 UTC [605] ERROR: relation "goose_db_version" does not exist at character 367502026-09-07 19:37:14.824 UTC [605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7512026-09-07 19:37:14.827 UTC [606] ERROR: relation "goose_db_version" does not exist at character 367522026-09-07 19:37:14.827 UTC [606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7532026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (16.12ms)7542026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (16.19ms)7552026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (17.39ms)7562026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (12.23ms)7572026/09/07 19:37:14 OK 20260905000000_add_claims.sql (8.68ms)7582026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000007592026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (21.65ms)7602026/09/07 19:37:14 OK 20260905000000_add_claims.sql (9.03ms)7612026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000007622026/09/07 19:37:14 OK 20241026095416_initial_model.sql (28.17ms)7632026/09/07 19:37:14 OK 20241026095416_initial_model.sql (25.82ms)7642026/09/07 19:37:14 OK 20260905000000_add_claims.sql (11.54ms)7652026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000007662026/09/07 19:37:14 OK 20251218171726_add_pins.sql (11.29ms)7672026/09/07 19:37:14 OK 20241026095416_initial_model.sql (27.07ms)7682026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.82ms)7692026-09-07 19:37:14.844 UTC [607] ERROR: relation "goose_db_version" does not exist at character 367702026-09-07 19:37:14.844 UTC [607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026/09/07 19:37:14 OK 1_commit_pending_closure.sql (8.06ms)7722026/09/07 19:37:14 OK 1_commit_pending_closure.sql (7.24ms)7732026/09/07 19:37:14 OK 20260905000000_add_claims.sql (7.93ms)7742026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000007752026/09/07 19:37:14 OK 1_commit_pending_closure.sql (5.2ms)7762026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (5.17ms)7772026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.72ms)7782026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (7.87ms)7792026/09/07 19:37:14 OK 20241026095416_initial_model.sql (20.9ms)7802026-09-07 19:37:14.850 UTC [608] ERROR: relation "goose_db_version" does not exist at character 367812026-09-07 19:37:14.850 UTC [608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7822026/09/07 19:37:14 OK 2_object_stats_trigger.sql (5.6ms)7832026/09/07 19:37:14 goose: up to current file version: 27842026/09/07 19:37:14 OK 2_object_stats_trigger.sql (6.08ms)7852026/09/07 19:37:14 goose: up to current file version: 27862026/09/07 19:37:14 OK 20251218171726_add_pins.sql (8.42ms)7872026/09/07 19:37:14 OK 2_object_stats_trigger.sql (5.88ms)7882026/09/07 19:37:14 goose: up to current file version: 27892026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.59ms)7902026/09/07 19:37:14 OK 1_commit_pending_closure.sql (6.73ms)7912026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.52ms)7922026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.44ms)7932026/09/07 19:37:14 OK 20241026095416_initial_model.sql (14.97ms)7942026/09/07 19:37:14 OK 20260905000000_add_claims.sql (13.77ms)7952026/09/07 19:37:14 OK 20241026095416_initial_model.sql (23.77ms)7962026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000007972026/09/07 19:37:14 OK 2_object_stats_trigger.sql (12.61ms)7982026/09/07 19:37:14 goose: up to current file version: 27992026/09/07 19:37:14 OK 20241026095416_initial_model.sql (26.79ms)8002026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (13.05ms)8012026/09/07 19:37:14 OK 20251218171726_add_pins.sql (12.8ms)8022026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (13.16ms)8032026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (13.59ms)8042026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (11.66ms)8052026-09-07 19:37:14.866 UTC [609] ERROR: relation "goose_db_version" does not exist at character 368062026-09-07 19:37:14.866 UTC [609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.54ms)8082026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.98ms)8092026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.07ms)8102026/09/07 19:37:14 OK 2_object_stats_trigger.sql (4.91ms)8112026/09/07 19:37:14 goose: up to current file version: 28122026/09/07 19:37:14 OK 20260905000000_add_claims.sql (6.79ms)8132026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008142026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (6.88ms)8152026/09/07 19:37:14 OK 20260905000000_add_claims.sql (8.2ms)8162026/09/07 19:37:14 OK 20260905000000_add_claims.sql (8.48ms)8172026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008182026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008192026/09/07 19:37:14 OK 20251218171726_add_pins.sql (8.36ms)8202026/09/07 19:37:14 OK 20251218171726_add_pins.sql (8.44ms)8212026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.55ms)8222026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.84ms)8232026/09/07 19:37:14 OK 20260905000000_add_claims.sql (4.86ms)8242026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008252026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.87ms)8262026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.99ms)8272026-09-07 19:37:14.879 UTC [610] ERROR: relation "goose_db_version" does not exist at character 368282026-09-07 19:37:14.879 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026-09-07 19:37:14.881 UTC [612] ERROR: relation "goose_db_version" does not exist at character 368302026-09-07 19:37:14.881 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-07 19:37:14.881 UTC [611] ERROR: relation "goose_db_version" does not exist at character 368322026-09-07 19:37:14.881 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-09-07 19:37:14.882 UTC [613] ERROR: relation "goose_db_version" does not exist at character 368342026-09-07 19:37:14.882 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026/09/07 19:37:14 OK 20241026095416_initial_model.sql (17.44ms)8362026-09-07 19:37:14.882 UTC [615] ERROR: relation "goose_db_version" does not exist at character 368372026-09-07 19:37:14.882 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026-09-07 19:37:14.883 UTC [614] ERROR: relation "goose_db_version" does not exist at character 368392026-09-07 19:37:14.883 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026/09/07 19:37:14 OK 2_object_stats_trigger.sql (5.07ms)8412026/09/07 19:37:14 goose: up to current file version: 28422026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (10.08ms)8432026/09/07 19:37:14 OK 20241026095416_initial_model.sql (18.01ms)8442026/09/07 19:37:14 OK 1_commit_pending_closure.sql (6.15ms)8452026/09/07 19:37:14 OK 2_object_stats_trigger.sql (5.19ms)8462026/09/07 19:37:14 goose: up to current file version: 28472026/09/07 19:37:14 OK 2_object_stats_trigger.sql (6.98ms)8482026/09/07 19:37:14 goose: up to current file version: 28492026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (9.93ms)8502026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (9.88ms)8512026/09/07 19:37:14 OK 2_object_stats_trigger.sql (2.1ms)8522026/09/07 19:37:14 goose: up to current file version: 28532026/09/07 19:37:14 OK 20241026095416_initial_model.sql (12.45ms)8542026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (5.16ms)8552026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)8562026-09-07 19:37:14.889 UTC [616] ERROR: relation "goose_db_version" does not exist at character 368572026-09-07 19:37:14.889 UTC [616] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/09/07 19:37:14 OK 20260905000000_add_claims.sql (7.07ms)8592026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008602026-09-07 19:37:14.892 UTC [617] ERROR: relation "goose_db_version" does not exist at character 368612026-09-07 19:37:14.892 UTC [617] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8622026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.2ms)8632026/09/07 19:37:14 OK 20260905000000_add_claims.sql (7.63ms)8642026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008652026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (6.06ms)8662026/09/07 19:37:14 OK 20260905000000_add_claims.sql (7.74ms)8672026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008682026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.56ms)8692026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.24ms)8702026/09/07 19:37:14 OK 1_commit_pending_closure.sql (3.23ms)8712026/09/07 19:37:14 OK 2_object_stats_trigger.sql (2.54ms)8722026/09/07 19:37:14 goose: up to current file version: 28732026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.38ms)8742026/09/07 19:37:14 OK 2_object_stats_trigger.sql (2.92ms)8752026/09/07 19:37:14 goose: up to current file version: 28762026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.83ms)8772026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (6.75ms)8782026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (7.37ms)8792026/09/07 19:37:14 OK 2_object_stats_trigger.sql (3.6ms)8802026/09/07 19:37:14 goose: up to current file version: 28812026-09-07 19:37:14.903 UTC [618] ERROR: relation "goose_db_version" does not exist at character 368822026-09-07 19:37:14.903 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026/09/07 19:37:14 OK 20241026095416_initial_model.sql (15.15ms)8842026/09/07 19:37:14 OK 20241026095416_initial_model.sql (15.4ms)8852026/09/07 19:37:14 OK 20260905000000_add_claims.sql (4.26ms)8862026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008872026/09/07 19:37:14 OK 20241026095416_initial_model.sql (15.15ms)8882026/09/07 19:37:14 OK 20241026095416_initial_model.sql (16.79ms)8892026/09/07 19:37:14 OK 20241026095416_initial_model.sql (16.49ms)8902026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)8912026/09/07 19:37:14 OK 20260905000000_add_claims.sql (5.36ms)8922026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000008932026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)8942026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.56ms)8952026/09/07 19:37:14 OK 1_commit_pending_closure.sql (3.7ms)8962026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.76ms)8972026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)8982026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)8992026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.05ms)9002026/09/07 19:37:14 OK 20241026095416_initial_model.sql (12.78ms)9012026/09/07 19:37:14 OK 20241026095416_initial_model.sql (21.9ms)9022026/09/07 19:37:14 OK 2_object_stats_trigger.sql (3.64ms)9032026/09/07 19:37:14 goose: up to current file version: 29042026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.19ms)9052026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.23ms)9062026/09/07 19:37:14 OK 20260905000000_add_claims.sql (6.4ms)9072026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009082026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.47ms)9092026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.38ms)9102026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4ms)9112026/09/07 19:37:14 OK 2_object_stats_trigger.sql (4.05ms)9122026/09/07 19:37:14 goose: up to current file version: 29132026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.98ms)9142026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.87ms)9152026/09/07 19:37:14 OK 1_commit_pending_closure.sql (3.77ms)9162026/09/07 19:37:14 OK 20241026095416_initial_model.sql (13.77ms)9172026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)9182026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (6.56ms)9192026/09/07 19:37:14 OK 2_object_stats_trigger.sql (4.04ms)9202026/09/07 19:37:14 goose: up to current file version: 29212026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (6.46ms)9222026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (5.91ms)9232026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.18ms)9242026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)9252026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (6.41ms)9262026/09/07 19:37:14 OK 20251218171726_add_pins.sql (6.32ms)9272026/09/07 19:37:14 OK 20241026095416_initial_model.sql (10.39ms)9282026/09/07 19:37:14 OK 20260905000000_add_claims.sql (2.79ms)9292026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009302026/09/07 19:37:14 OK 20260905000000_add_claims.sql (4.66ms)9312026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009322026/09/07 19:37:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9332026/09/07 19:37:14 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)9342026/09/07 19:37:14 OK 20260905000000_add_claims.sql (5.5ms)9352026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)9362026/09/07 19:37:14 OK 20251218171726_add_pins.sql (5.31ms)9372026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009382026/09/07 19:37:14 OK 1_commit_pending_closure.sql (2.92ms)9392026/09/07 19:37:14 OK 20260905000000_add_claims.sql (5.24ms)9402026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009412026/09/07 19:37:14 OK 20260905000000_add_claims.sql (5.37ms)9422026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009432026/09/07 19:37:14 OK 1_commit_pending_closure.sql (4.16ms)9442026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (5.68ms)9452026/09/07 19:37:14 OK 2_object_stats_trigger.sql (967.07µs)9462026/09/07 19:37:14 goose: up to current file version: 29472026/09/07 19:37:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst948--- PASS: TestCompleteMultipartUnregistered (0.38s)949=== CONT TestCacheStatsHandler9502026/09/07 19:37:14 OK 2_object_stats_trigger.sql (2.43ms)9512026/09/07 19:37:14 goose: up to current file version: 29522026/09/07 19:37:14 OK 1_commit_pending_closure.sql (3.46ms)9532026/09/07 19:37:14 OK 20251218171726_add_pins.sql (4.57ms)9542026/09/07 19:37:14 OK 20260905000000_add_claims.sql (3.77ms)9552026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009562026/09/07 19:37:14 OK 1_commit_pending_closure.sql (3.24ms)9572026/09/07 19:37:14 OK 1_commit_pending_closure.sql (3.41ms)9582026/09/07 19:37:14 OK 20260905000000_add_claims.sql (2.93ms)9592026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009602026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)9612026/09/07 19:37:14 OK 2_object_stats_trigger.sql (1.09ms)9622026/09/07 19:37:14 goose: up to current file version: 29632026/09/07 19:37:14 OK 2_object_stats_trigger.sql (1.42ms)9642026/09/07 19:37:14 goose: up to current file version: 29652026/09/07 19:37:14 OK 2_object_stats_trigger.sql (1.44ms)9662026/09/07 19:37:14 goose: up to current file version: 29672026/09/07 19:37:14 OK 1_commit_pending_closure.sql (1.73ms)9682026/09/07 19:37:14 OK 2_object_stats_trigger.sql (833.81µs)9692026/09/07 19:37:14 goose: up to current file version: 29702026/09/07 19:37:14 OK 1_commit_pending_closure.sql (2.65ms)9712026/09/07 19:37:14 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)9722026/09/07 19:37:14 OK 2_object_stats_trigger.sql (772.33µs)9732026/09/07 19:37:14 goose: up to current file version: 29742026/09/07 19:37:14 OK 20260905000000_add_claims.sql (3.24ms)9752026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009762026/09/07 19:37:14 OK 20260905000000_add_claims.sql (2.04ms)9772026/09/07 19:37:14 goose: successfully migrated database to version: 202609050000009782026/09/07 19:37:14 OK 1_commit_pending_closure.sql (7.84ms)9792026/09/07 19:37:14 OK 1_commit_pending_closure.sql (8.56ms)9802026/09/07 19:37:14 OK 2_object_stats_trigger.sql (1.81ms)9812026/09/07 19:37:14 goose: up to current file version: 29822026/09/07 19:37:14 OK 2_object_stats_trigger.sql (1.2ms)9832026/09/07 19:37:14 goose: up to current file version: 29842026/09/07 19:37:14 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"985--- PASS: TestService_AuthMiddleware (0.43s)986=== CONT TestReadProxyRootRedirectsToIndexHTML9872026/09/07 19:37:14 INFO Received uploads request method=POST path=/api/pending_closures9882026-09-07 19:37:15.004 UTC [626] ERROR: relation "goose_db_version" does not exist at character 369892026-09-07 19:37:15.004 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC990--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.47s)991=== CONT TestCacheConfigHandler992=== RUN TestCacheConfigHandler/full_config,_no_issuer993=== PAUSE TestCacheConfigHandler/full_config,_no_issuer994=== RUN TestCacheConfigHandler/no_cache_url_configured995=== PAUSE TestCacheConfigHandler/no_cache_url_configured996=== RUN TestCacheConfigHandler/no_signing_keys997=== PAUSE TestCacheConfigHandler/no_signing_keys998=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator999=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1000=== CONT TestReadProxyConditionalGet10012026/09/07 19:37:15 OK 20241026095416_initial_model.sql (10.82ms)10022026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10032026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)10042026/09/07 19:37:15 OK 20251218171726_add_pins.sql (4.22ms)10052026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)10062026/09/07 19:37:15 OK 20260905000000_add_claims.sql (4.3ms)10072026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000010082026/09/07 19:37:15 OK 1_commit_pending_closure.sql (2.93ms)10092026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10102026/09/07 19:37:15 OK 2_object_stats_trigger.sql (8.93ms)10112026/09/07 19:37:15 goose: up to current file version: 210122026-09-07 19:37:15.061 UTC [629] ERROR: relation "goose_db_version" does not exist at character 3610132026-09-07 19:37:15.061 UTC [629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10142026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10152026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10162026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10172026/09/07 19:37:15 OK 20241026095416_initial_model.sql (11.33ms)10182026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)10192026/09/07 19:37:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10202026/09/07 19:37:15 OK 20251218171726_add_pins.sql (2.51ms)10212026-09-07 19:37:15.093 UTC [630] ERROR: relation "goose_db_version" does not exist at character 3610222026-09-07 19:37:15.093 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10232026/09/07 19:37:15 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLjZlMWEwMmFjLWI1N2EtNDNiNS1hYzUyLWY4NGY4MDQ0Y2VlMXgxNzg4ODA5ODM1MDU4MTg4Nzc010242026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (4.01ms)10252026/09/07 19:37:15 OK 20260905000000_add_claims.sql (2.65ms)10262026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000010272026/09/07 19:37:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLjZlMWEwMmFjLWI1N2EtNDNiNS1hYzUyLWY4NGY4MDQ0Y2VlMXgxNzg4ODA5ODM1MDU4MTg4Nzc0 parts=110282026/09/07 19:37:15 OK 1_commit_pending_closure.sql (1.94ms)1029--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.54s)1030=== CONT TestService_ReadScope_PublicByDefault10312026/09/07 19:37:15 OK 2_object_stats_trigger.sql (891.71µs)10322026/09/07 19:37:15 goose: up to current file version: 210332026/09/07 19:37:15 OK 20241026095416_initial_model.sql (9.7ms)10342026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)10352026/09/07 19:37:15 OK 20251218171726_add_pins.sql (3.68ms)10362026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)10372026/09/07 19:37:15 OK 20260905000000_add_claims.sql (3.89ms)10382026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000010392026/09/07 19:37:15 OK 1_commit_pending_closure.sql (3.4ms)10402026/09/07 19:37:15 OK 2_object_stats_trigger.sql (2.61ms)10412026/09/07 19:37:15 goose: up to current file version: 21042--- PASS: TestGCBugBareHashReferences (0.58s)1043=== CONT TestReadProxyHead10442026-09-07 19:37:15.172 UTC [635] ERROR: relation "goose_db_version" does not exist at character 3610452026-09-07 19:37:15.172 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10462026/09/07 19:37:15 OK 20241026095416_initial_model.sql (10.99ms)10472026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)10482026/09/07 19:37:15 OK 20251218171726_add_pins.sql (3.55ms)10492026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (3.03ms)10502026-09-07 19:37:15.202 UTC [636] ERROR: relation "goose_db_version" does not exist at character 3610512026-09-07 19:37:15.202 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10522026/09/07 19:37:15 OK 20260905000000_add_claims.sql (3.27ms)10532026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000010542026/09/07 19:37:15 OK 1_commit_pending_closure.sql (1.83ms)10552026/09/07 19:37:15 OK 2_object_stats_trigger.sql (902.91µs)10562026/09/07 19:37:15 goose: up to current file version: 210572026/09/07 19:37:15 OK 20241026095416_initial_model.sql (10.51ms)10582026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)10592026/09/07 19:37:15 OK 20251218171726_add_pins.sql (3.38ms)10602026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (3.13ms)10612026/09/07 19:37:15 OK 20260905000000_add_claims.sql (3.67ms)10622026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000010632026/09/07 19:37:15 OK 1_commit_pending_closure.sql (1.97ms)10642026/09/07 19:37:15 OK 2_object_stats_trigger.sql (886.37µs)10652026/09/07 19:37:15 goose: up to current file version: 210662026/09/07 19:37:15 INFO Received cleanup request method=DELETE path=/api/pending_closures10672026/09/07 19:37:15 INFO Aborted multipart uploads count=010682026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10692026/09/07 19:37:15 INFO Received cleanup request method=DELETE path=/api/pending_closures10702026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures10712026/09/07 19:37:15 INFO Aborted multipart uploads count=110722026/09/07 19:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10732026-09-07 19:37:15.332 UTC [601] ERROR: Closure does not exist: id=110742026-09-07 19:37:15.332 UTC [601] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10752026-09-07 19:37:15.332 UTC [601] STATEMENT: -- name: CommitPendingClosure :exec1076 SELECT commit_pending_closure($1::bigint)1077 1078--- PASS: TestService_cleanupPendingClosuresHandler (0.78s)1079=== CONT TestService_RequireScope_OIDC10802026/09/07 19:37:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43247/oidc10812026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures1082--- PASS: TestService_Rustfstest (0.81s)1083=== CONT TestReadProxyInvalidPath10842026-09-07 19:37:15.435 UTC [640] ERROR: relation "goose_db_version" does not exist at character 3610852026-09-07 19:37:15.435 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/09/07 19:37:15 OK 20241026095416_initial_model.sql (10.92ms)10872026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (3.41ms)10882026/09/07 19:37:15 OK 20251218171726_add_pins.sql (5.76ms)10892026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)10902026/09/07 19:37:15 OK 20260905000000_add_claims.sql (3.54ms)10912026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000010922026/09/07 19:37:15 OK 1_commit_pending_closure.sql (3.48ms)10932026/09/07 19:37:15 OK 2_object_stats_trigger.sql (2.29ms)10942026/09/07 19:37:15 goose: up to current file version: 21095--- PASS: TestReadRedirectUsesPublicS3URL (0.92s)1096=== CONT TestService_AuthMiddleware_OIDC1097=== NAME TestPinProtectsFromGC1098 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC1683148970/001/store/sghkvy1jbg2czr4sd3fxribmd1b2jp8n-pinned-file.txt1099 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC1683148970/001/store/gb7dnv60j0fj49zn51vx3vmbnm3cc4mq-unpinned-file.txt11002026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11012026/09/07 19:37:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37291/oidc11022026/09/07 19:37:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11032026-09-07 19:37:15.505 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611042026-09-07 19:37:15.505 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/09/07 19:37:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11062026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures1107--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.96s)1108=== CONT TestReadProxy40411092026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11102026/09/07 19:37:15 OK 20241026095416_initial_model.sql (9.89ms)11112026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (5.24ms)11122026/09/07 19:37:15 OK 20251218171726_add_pins.sql (5.02ms)11132026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11142026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)11152026/09/07 19:37:15 OK 20260905000000_add_claims.sql (5.07ms)11162026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000011172026/09/07 19:37:15 OK 1_commit_pending_closure.sql (3.32ms)11182026-09-07 19:37:15.554 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3611192026-09-07 19:37:15.554 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11202026/09/07 19:37:15 OK 2_object_stats_trigger.sql (2.47ms)11212026/09/07 19:37:15 goose: up to current file version: 21122--- PASS: TestReadProxyDisabled (0.82s)1123=== CONT TestService_ReadAuthMiddleware11242026/09/07 19:37:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11252026/09/07 19:37:15 OK 20241026095416_initial_model.sql (11.22ms)11262026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)11272026/09/07 19:37:15 OK 20251218171726_add_pins.sql (4.42ms)11282026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)11292026/09/07 19:37:15 OK 20260905000000_add_claims.sql (4.59ms)11302026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000011312026/09/07 19:37:15 OK 1_commit_pending_closure.sql (3.39ms)11322026/09/07 19:37:15 OK 2_object_stats_trigger.sql (1.72ms)11332026/09/07 19:37:15 goose: up to current file version: 211342026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11352026-09-07 19:37:15.603 UTC [740] ERROR: relation "goose_db_version" does not exist at character 3611362026-09-07 19:37:15.603 UTC [740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11372026/09/07 19:37:15 WARN claim: cannot clear write deadline error="feature not supported"11382026/09/07 19:37:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11392026/09/07 19:37:15 INFO Uploading sghkvy1jbg2czr4sd3fxribmd1b2jp8n-pinned-file.txt (128B)11402026/09/07 19:37:15 WARN claim: cannot clear write deadline error="feature not supported"11412026/09/07 19:37:15 WARN claim: cannot clear write deadline error="feature not supported"11422026/09/07 19:37:15 OK 20241026095416_initial_model.sql (9.64ms)11432026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11442026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)11452026/09/07 19:37:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11462026-09-07 19:37:15.634 UTC [758] ERROR: relation "goose_db_version" does not exist at character 3611472026-09-07 19:37:15.634 UTC [758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026/09/07 19:37:15 OK 20251218171726_add_pins.sql (4.73ms)11492026/09/07 19:37:15 WARN Failed to register uploaded object key=sghkvy1jbg2czr4sd3fxribmd1b2jp8n.ls error="server returned 404: 404 page not found\n"11502026/09/07 19:37:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11512026/09/07 19:37:15 INFO Signed narinfos id=1 count=111522026/09/07 19:37:15 INFO Uploading 1 narinfos11532026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (5.55ms)11542026/09/07 19:37:15 WARN Failed to register uploaded object key=sghkvy1jbg2czr4sd3fxribmd1b2jp8n.narinfo error="server returned 404: 404 page not found\n"11552026/09/07 19:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11562026/09/07 19:37:15 OK 20260905000000_add_claims.sql (5.3ms)11572026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000011582026/09/07 19:37:15 OK 1_commit_pending_closure.sql (2.69ms)11592026/09/07 19:37:15 OK 2_object_stats_trigger.sql (1.81ms)11602026/09/07 19:37:15 goose: up to current file version: 211612026/09/07 19:37:15 INFO Completed upload id=111622026/09/07 19:37:15 INFO Upload complete. (124ms)11632026/09/07 19:37:15 OK 20241026095416_initial_model.sql (10.72ms)11642026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)11652026/09/07 19:37:15 OK 20251218171726_add_pins.sql (5ms)11662026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)11672026/09/07 19:37:15 OK 20260905000000_add_claims.sql (4.04ms)11682026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000011692026/09/07 19:37:15 OK 1_commit_pending_closure.sql (1.99ms)11702026/09/07 19:37:15 OK 2_object_stats_trigger.sql (1.52ms)11712026/09/07 19:37:15 goose: up to current file version: 21172=== NAME TestClientWithDependencies1173 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies146032642/001/store/27rnjhri3ks98sfvlyv2zmxqp8dpnx8q-test-script1174=== NAME TestClientMultipleUploads1175 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads3911451612/001/store/ivhw9vc067plv9v0fh7j34321mqn749p-test-file-0.txt1176=== NAME TestClientIntegration1177 client_integration_test.go:277: Created store path: /build/TestClientIntegration2953984859/002/store/zhca2h320vjap50sm3vjhnwdrwjxhq1l-test-file.txt1178=== NAME TestClientWithDependencies1179 client_integration_test.go:596: Found 1 dependencies (including self)11802026/09/07 19:37:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1181=== NAME TestClientMultipleUploads1182 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads3911451612/001/store/fcm84r13fqp6sd1pvnff65n3jhwd4jmz-test-file-1.txt1183--- PASS: TestReadRedirectKeepsNarinfoProxied (1.15s)1184=== CONT TestClaim_GCMarkedOutputCountsAsAbsent11852026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11862026/09/07 19:37:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11872026/09/07 19:37:15 INFO Uploading gb7dnv60j0fj49zn51vx3vmbnm3cc4mq-unpinned-file.txt (128B)11882026/09/07 19:37:15 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1189=== NAME TestClientMultipleUploads1190 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads3911451612/001/store/4s5vxp677xc9b7i2dwvl1k3g526pjg1w-test-file-2.txt11912026/09/07 19:37:15 WARN Failed to register uploaded object key=gb7dnv60j0fj49zn51vx3vmbnm3cc4mq.ls error="server returned 404: 404 page not found\n"11922026/09/07 19:37:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11932026/09/07 19:37:15 INFO Signed narinfos id=2 count=111942026/09/07 19:37:15 INFO Uploading 1 narinfos11952026/09/07 19:37:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11962026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures11972026/09/07 19:37:15 WARN Failed to register uploaded object key=gb7dnv60j0fj49zn51vx3vmbnm3cc4mq.narinfo error="server returned 404: 404 page not found\n"11982026/09/07 19:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11992026/09/07 19:37:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12002026/09/07 19:37:15 INFO Uploading 27rnjhri3ks98sfvlyv2zmxqp8dpnx8q-test-script (136B)12012026/09/07 19:37:15 INFO Completed upload id=212022026/09/07 19:37:15 INFO Upload complete. (146ms)12032026/09/07 19:37:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12042026/09/07 19:37:15 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12052026-09-07 19:37:15.848 UTC [991] ERROR: relation "goose_db_version" does not exist at character 3612062026-09-07 19:37:15.848 UTC [991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12072026/09/07 19:37:15 WARN Failed to register uploaded object key=27rnjhri3ks98sfvlyv2zmxqp8dpnx8q.ls error="server returned 404: 404 page not found\n"12082026/09/07 19:37:15 OK 20241026095416_initial_model.sql (11.11ms)12092026/09/07 19:37:15 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)12102026/09/07 19:37:15 OK 20251218171726_add_pins.sql (4.11ms)12112026/09/07 19:37:15 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)12122026/09/07 19:37:15 INFO Received create pin request method=POST path=/api/pins/myapp12132026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures12142026/09/07 19:37:15 OK 20260905000000_add_claims.sql (4.16ms)12152026/09/07 19:37:15 goose: successfully migrated database to version: 2026090500000012162026/09/07 19:37:15 OK 1_commit_pending_closure.sql (2.05ms)12172026/09/07 19:37:15 OK 2_object_stats_trigger.sql (730.77µs)12182026/09/07 19:37:15 goose: up to current file version: 212192026/09/07 19:37:15 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1683148970/001/store/sghkvy1jbg2czr4sd3fxribmd1b2jp8n-pinned-file.txt narinfo_key=sghkvy1jbg2czr4sd3fxribmd1b2jp8n.narinfo12202026/09/07 19:37:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12212026/09/07 19:37:15 INFO Uploading zhca2h320vjap50sm3vjhnwdrwjxhq1l-test-file.txt (152B)12222026/09/07 19:37:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures12232026/09/07 19:37:15 INFO Garbage collection started12242026/09/07 19:37:15 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12252026/09/07 19:37:15 INFO Aborted multipart uploads count=012262026/09/07 19:37:15 WARN Failed to register uploaded object key=zhca2h320vjap50sm3vjhnwdrwjxhq1l.ls error="server returned 404: 404 page not found\n"12272026/09/07 19:37:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12282026/09/07 19:37:15 INFO Signed narinfos id=1 count=112292026/09/07 19:37:15 INFO Uploading 1 narinfos12302026/09/07 19:37:15 WARN Force mode enabled - objects will be deleted immediately without grace period12312026/09/07 19:37:15 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12322026/09/07 19:37:15 WARN Failed to register uploaded object key=log/1nccsiwflpp6xxd9jim12wg2vnv45lk9-test-script.drv error="server returned 404: 404 page not found\n"12332026/09/07 19:37:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12342026/09/07 19:37:15 INFO Signed narinfos id=1 count=112352026/09/07 19:37:15 INFO Uploading 1 narinfos12362026/09/07 19:37:15 WARN Failed to register uploaded object key=zhca2h320vjap50sm3vjhnwdrwjxhq1l.narinfo error="server returned 404: 404 page not found\n"12372026/09/07 19:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12382026/09/07 19:37:15 WARN Failed to register uploaded object key=27rnjhri3ks98sfvlyv2zmxqp8dpnx8q.narinfo error="server returned 404: 404 page not found\n"12392026/09/07 19:37:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12402026/09/07 19:37:15 INFO Completed upload id=112412026/09/07 19:37:15 INFO Upload complete. (138ms)12422026/09/07 19:37:15 INFO Completed upload id=112432026/09/07 19:37:15 INFO Upload complete. (147ms)1244=== NAME TestClientIntegration1245 client_integration_test.go:293: Retrieved narinfo from S3:1246 StorePath: /build/TestClientIntegration2953984859/002/store/zhca2h320vjap50sm3vjhnwdrwjxhq1l-test-file.txt1247 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1248 Compression: zstd1249 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11250 NarSize: 1521251 References: 1252 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11253=== NAME TestClientWithDependencies1254 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies146032642/001/store) requires matching store prefix1255=== NAME TestClientIntegration1256 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1257 client_integration_test.go:294: Decompressed .ls content (64 bytes):1258 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1259 client_integration_test.go:297: Testing garbage collection...1260--- PASS: TestClientWithDependencies (1.31s)1261=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12622026/09/07 19:37:15 INFO Aborted multipart uploads count=012632026/09/07 19:37:15 WARN Force mode enabled - objects will be deleted immediately without grace period12642026/09/07 19:37:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012652026/09/07 19:37:15 INFO Vacuumed table table=pending_closures12662026/09/07 19:37:15 INFO Vacuumed table table=pending_objects12672026/09/07 19:37:15 INFO Vacuumed table table=multipart_uploads12682026/09/07 19:37:15 INFO Vacuumed table table=closures12692026/09/07 19:37:15 INFO Vacuumed table table=objects12702026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures1271--- PASS: TestGCMetrics (1.33s)1272=== CONT TestReadProxyNarStreaming12732026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures12742026/09/07 19:37:15 INFO Received uploads request method=POST path=/api/pending_closures12752026/09/07 19:37:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures12762026/09/07 19:37:15 INFO Garbage collection started12772026/09/07 19:37:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12782026/09/07 19:37:15 INFO Uploading 4s5vxp677xc9b7i2dwvl1k3g526pjg1w-test-file-2.txt (160B)12792026/09/07 19:37:15 INFO Uploading fcm84r13fqp6sd1pvnff65n3jhwd4jmz-test-file-1.txt (160B)12802026/09/07 19:37:15 INFO Uploading ivhw9vc067plv9v0fh7j34321mqn749p-test-file-0.txt (160B)12812026/09/07 19:37:15 INFO Aborted multipart uploads count=012822026/09/07 19:37:15 WARN Force mode enabled - objects will be deleted immediately without grace period12832026/09/07 19:37:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12842026/09/07 19:37:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12852026/09/07 19:37:15 WARN Failed to register uploaded object key=ivhw9vc067plv9v0fh7j34321mqn749p.ls error="server returned 404: 404 page not found\n"12862026/09/07 19:37:15 WARN Failed to register uploaded object key=4s5vxp677xc9b7i2dwvl1k3g526pjg1w.ls error="server returned 404: 404 page not found\n"12872026-09-07 19:37:16.000 UTC [1128] ERROR: relation "goose_db_version" does not exist at character 3612882026-09-07 19:37:16.000 UTC [1128] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12892026/09/07 19:37:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12902026/09/07 19:37:16 WARN Failed to register uploaded object key=fcm84r13fqp6sd1pvnff65n3jhwd4jmz.ls error="server returned 404: 404 page not found\n"12912026/09/07 19:37:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12922026/09/07 19:37:16 INFO Signed narinfos id=1 count=112932026/09/07 19:37:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12942026/09/07 19:37:16 INFO Signed narinfos id=2 count=112952026/09/07 19:37:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign12962026/09/07 19:37:16 INFO Signed narinfos id=3 count=112972026/09/07 19:37:16 INFO Uploading 3 narinfos12982026/09/07 19:37:16 OK 20241026095416_initial_model.sql (13.98ms)12992026/09/07 19:37:16 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)13002026/09/07 19:37:16 WARN Failed to register uploaded object key=ivhw9vc067plv9v0fh7j34321mqn749p.narinfo error="server returned 404: 404 page not found\n"13012026/09/07 19:37:16 WARN Failed to register uploaded object key=4s5vxp677xc9b7i2dwvl1k3g526pjg1w.narinfo error="server returned 404: 404 page not found\n"13022026/09/07 19:37:16 WARN Failed to register uploaded object key=fcm84r13fqp6sd1pvnff65n3jhwd4jmz.narinfo error="server returned 404: 404 page not found\n"13032026/09/07 19:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1304--- PASS: TestReadProxyRangeRequest (1.41s)1305=== CONT TestClientCADerivations13062026/09/07 19:37:16 OK 20251218171726_add_pins.sql (4.29ms)13072026/09/07 19:37:16 INFO Completed upload id=113082026/09/07 19:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13092026/09/07 19:37:16 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)13102026/09/07 19:37:16 INFO Completed upload id=213112026/09/07 19:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13122026/09/07 19:37:16 INFO Completed upload id=313132026/09/07 19:37:16 INFO Upload complete. (174ms)1314=== NAME TestClientMultipleUploads13152026/09/07 19:37:16 OK 20260905000000_add_claims.sql (3.45ms)1316 client_integration_test.go:350: Uploaded 3 paths in 235.021724ms13172026/09/07 19:37:16 goose: successfully migrated database to version: 2026090500000013182026-09-07 19:37:16.039 UTC [1130] ERROR: relation "goose_db_version" does not exist at character 3613192026-09-07 19:37:16.039 UTC [1130] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13202026/09/07 19:37:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13212026/09/07 19:37:16 OK 1_commit_pending_closure.sql (10.7ms)1322--- PASS: TestClientMultipleUploads (1.44s)1323=== CONT TestService_AuthMiddleware_MTLSProxyHeader13242026/09/07 19:37:16 OK 2_object_stats_trigger.sql (4.73ms)13252026/09/07 19:37:16 goose: up to current file version: 213262026/09/07 19:37:16 OK 20241026095416_initial_model.sql (13.03ms)13272026/09/07 19:37:16 OK 20251210153512_drop_unused_gin_index.sql (3.59ms)13282026/09/07 19:37:16 OK 20251218171726_add_pins.sql (5.3ms)13292026/09/07 19:37:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLmI3MzEzNTMwLThhMjYtNGYyMi04NGI3LWI3YmRlYzljYjY0YXgxNzg4ODA5ODM1MDM1Nzc3MDYw parts=1013302026/09/07 19:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13312026/09/07 19:37:16 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)13322026/09/07 19:37:16 INFO Completed upload id=113332026/09/07 19:37:16 OK 20260905000000_add_claims.sql (5.14ms)13342026/09/07 19:37:16 goose: successfully migrated database to version: 2026090500000013352026/09/07 19:37:16 INFO Received uploads request method=POST path=/api/pending_closures13362026/09/07 19:37:16 INFO Received uploads request method=POST path=/api/pending_closures13372026/09/07 19:37:16 OK 1_commit_pending_closure.sql (4.21ms)13382026/09/07 19:37:16 OK 2_object_stats_trigger.sql (2.45ms)13392026/09/07 19:37:16 goose: up to current file version: 213402026-09-07 19:37:16.105 UTC [1134] ERROR: relation "goose_db_version" does not exist at character 3613412026-09-07 19:37:16.105 UTC [1134] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13422026/09/07 19:37:16 OK 20241026095416_initial_model.sql (10.29ms)13432026/09/07 19:37:16 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)13442026/09/07 19:37:16 OK 20251218171726_add_pins.sql (3.17ms)13452026-09-07 19:37:16.133 UTC [1135] ERROR: relation "goose_db_version" does not exist at character 3613462026-09-07 19:37:16.133 UTC [1135] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13472026/09/07 19:37:16 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)13482026/09/07 19:37:16 OK 20260905000000_add_claims.sql (3.78ms)13492026/09/07 19:37:16 goose: successfully migrated database to version: 2026090500000013502026/09/07 19:37:16 OK 1_commit_pending_closure.sql (1.87ms)13512026/09/07 19:37:16 OK 2_object_stats_trigger.sql (930.63µs)13522026/09/07 19:37:16 goose: up to current file version: 213532026/09/07 19:37:16 OK 20241026095416_initial_model.sql (9.61ms)13542026/09/07 19:37:16 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)13552026/09/07 19:37:16 OK 20251218171726_add_pins.sql (3.45ms)13562026/09/07 19:37:16 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)13572026/09/07 19:37:16 OK 20260905000000_add_claims.sql (4.86ms)13582026/09/07 19:37:16 goose: successfully migrated database to version: 2026090500000013592026/09/07 19:37:16 OK 1_commit_pending_closure.sql (2.12ms)13602026/09/07 19:37:16 OK 2_object_stats_trigger.sql (805.03µs)13612026/09/07 19:37:16 goose: up to current file version: 213622026/09/07 19:37:16 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13632026/09/07 19:37:16 WARN Found objects in DB but missing from S3, will re-upload count=11364--- PASS: TestService_verifyS3Integrity (2.24s)1365=== CONT TestReadProxyNarinfoAlreadyDecompressed13662026/09/07 19:37:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13672026/09/07 19:37:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLjk5M2VmNDdjLTgxNjctNDMyMy04ZGJlLTc0Y2YzNDhhNjNlOXgxNzg4ODA5ODM1MDg0MzA3Mzk4 parts=1013682026/09/07 19:37:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13692026/09/07 19:37:16 INFO Completed upload id=113702026/09/07 19:37:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013712026/09/07 19:37:16 INFO Received uploads request method=POST path=/api/pending_closures13722026/09/07 19:37:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures13732026/09/07 19:37:16 INFO Aborted multipart uploads count=01374--- PASS: TestCacheStatsHandler (1.92s)1375=== CONT TestClaim_StreamsThroughServer13762026/09/07 19:37:16 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=013772026/09/07 19:37:16 INFO Vacuumed table table=pending_closures13782026/09/07 19:37:16 INFO Vacuumed table table=pending_objects13792026-09-07 19:37:16.865 UTC [1141] ERROR: relation "goose_db_version" does not exist at character 3613802026-09-07 19:37:16.865 UTC [1141] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13812026/09/07 19:37:16 INFO Vacuumed table table=multipart_uploads13822026/09/07 19:37:16 INFO Vacuumed table table=closures13832026/09/07 19:37:16 INFO Vacuumed table table=objects13842026/09/07 19:37:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001385--- PASS: TestReadRedirectNar (2.27s)1386=== CONT TestReadProxyNarinfo1387--- PASS: TestService_createPendingClosureHandler (2.33s)1388=== CONT TestClaim_InputsTouched13892026/09/07 19:37:16 OK 20241026095416_initial_model.sql (13.82ms)13902026/09/07 19:37:16 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)13912026/09/07 19:37:16 OK 20251218171726_add_pins.sql (4.45ms)13922026/09/07 19:37:16 OK 20260628120000_add_object_size_and_stats.sql (10.16ms)13932026/09/07 19:37:16 OK 20260905000000_add_claims.sql (4.75ms)13942026/09/07 19:37:16 goose: successfully migrated database to version: 2026090500000013952026/09/07 19:37:16 OK 1_commit_pending_closure.sql (4.35ms)13962026/09/07 19:37:16 OK 2_object_stats_trigger.sql (2.93ms)13972026/09/07 19:37:16 goose: up to current file version: 213982026-09-07 19:37:16.928 UTC [1147] ERROR: relation "goose_db_version" does not exist at character 3613992026-09-07 19:37:16.928 UTC [1147] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14002026/09/07 19:37:16 OK 20241026095416_initial_model.sql (17.33ms)14012026/09/07 19:37:16 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)14022026/09/07 19:37:16 OK 20251218171726_add_pins.sql (6.77ms)14032026/09/07 19:37:16 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)14042026/09/07 19:37:16 OK 20260905000000_add_claims.sql (5.28ms)14052026/09/07 19:37:16 goose: successfully migrated database to version: 2026090500000014062026/09/07 19:37:16 OK 1_commit_pending_closure.sql (2.11ms)14072026-09-07 19:37:16.985 UTC [1149] ERROR: relation "goose_db_version" does not exist at character 3614082026-09-07 19:37:16.985 UTC [1149] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14092026-09-07 19:37:16.985 UTC [1148] ERROR: relation "goose_db_version" does not exist at character 3614102026-09-07 19:37:16.985 UTC [1148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14112026/09/07 19:37:16 OK 2_object_stats_trigger.sql (2.99ms)14122026/09/07 19:37:16 goose: up to current file version: 214132026/09/07 19:37:17 OK 20241026095416_initial_model.sql (11.6ms)14142026/09/07 19:37:17 OK 20241026095416_initial_model.sql (12.25ms)14152026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)14162026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)14172026/09/07 19:37:17 OK 20251218171726_add_pins.sql (5.31ms)14182026/09/07 19:37:17 OK 20251218171726_add_pins.sql (6.66ms)14192026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)14202026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)14212026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.06ms)14222026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000014232026/09/07 19:37:17 OK 20260905000000_add_claims.sql (5.06ms)14242026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000014252026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.62ms)14262026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.16ms)14272026/09/07 19:37:17 OK 2_object_stats_trigger.sql (967.87µs)14282026/09/07 19:37:17 goose: up to current file version: 214292026/09/07 19:37:17 OK 2_object_stats_trigger.sql (911.29µs)14302026/09/07 19:37:17 goose: up to current file version: 214312026/09/07 19:37:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14322026/09/07 19:37:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14332026/09/07 19:37:17 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLmNlMmM0MTYyLTgxYmItNDVmNy04MjZlLWMxZmIzMTFlZGYyYXgxNzg4ODA5ODM1MzU2MTE2MzE5 parts=1214342026/09/07 19:37:17 INFO Received uploads request method=POST path=/api/pending_closures1435--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.52s)1436=== CONT TestClaim_FailWithoutKindReleases14372026-09-07 19:37:17.143 UTC [1152] ERROR: relation "goose_db_version" does not exist at character 3614382026-09-07 19:37:17.143 UTC [1152] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14392026/09/07 19:37:17 OK 20241026095416_initial_model.sql (10.2ms)14402026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)14412026/09/07 19:37:17 OK 20251218171726_add_pins.sql (3.6ms)14422026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)14432026/09/07 19:37:17 OK 20260905000000_add_claims.sql (2.95ms)14442026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000014452026/09/07 19:37:17 OK 1_commit_pending_closure.sql (1.98ms)14462026/09/07 19:37:17 OK 2_object_stats_trigger.sql (875.47µs)14472026/09/07 19:37:17 goose: up to current file version: 214482026/09/07 19:37:17 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLmEyNDdjOGQ1LTZmOTktNDg2MC04Y2UwLTA1NzU5ODFkMWU1MngxNzg4ODA5ODM1NjM1MDM5MDgw parts=1014492026/09/07 19:37:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14502026/09/07 19:37:17 INFO Signed narinfos id=1 count=114512026/09/07 19:37:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14522026/09/07 19:37:17 INFO Received uploads request method=POST path=/api/pending_closures14532026/09/07 19:37:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14542026/09/07 19:37:17 INFO Signed narinfos id=2 count=114552026/09/07 19:37:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1456--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.27s)1457=== CONT TestIsValidCachePath1458=== RUN TestIsValidCachePath/narinfo1459=== PAUSE TestIsValidCachePath/narinfo1460=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1461=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1462=== RUN TestIsValidCachePath/nar_zst1463=== PAUSE TestIsValidCachePath/nar_zst1464=== RUN TestIsValidCachePath/nar_xz1465=== PAUSE TestIsValidCachePath/nar_xz1466=== RUN TestIsValidCachePath/nar_bz21467=== PAUSE TestIsValidCachePath/nar_bz21468=== RUN TestIsValidCachePath/nar_uncompressed1469=== PAUSE TestIsValidCachePath/nar_uncompressed1470=== RUN TestIsValidCachePath/ls1471=== PAUSE TestIsValidCachePath/ls1472=== RUN TestIsValidCachePath/log1473=== PAUSE TestIsValidCachePath/log1474=== RUN TestIsValidCachePath/realisation1475=== PAUSE TestIsValidCachePath/realisation1476=== RUN TestIsValidCachePath/nix-cache-info1477=== PAUSE TestIsValidCachePath/nix-cache-info1478=== RUN TestIsValidCachePath/index.html1479=== PAUSE TestIsValidCachePath/index.html1480=== RUN TestIsValidCachePath/traversal_parent1481=== PAUSE TestIsValidCachePath/traversal_parent1482=== RUN TestIsValidCachePath/traversal_in_middle1483=== PAUSE TestIsValidCachePath/traversal_in_middle1484=== RUN TestIsValidCachePath/invalid_char_e1485=== PAUSE TestIsValidCachePath/invalid_char_e1486=== RUN TestIsValidCachePath/invalid_char_u1487=== PAUSE TestIsValidCachePath/invalid_char_u1488=== RUN TestIsValidCachePath/random_path1489=== PAUSE TestIsValidCachePath/random_path1490=== RUN TestIsValidCachePath/empty1491=== PAUSE TestIsValidCachePath/empty1492=== RUN TestIsValidCachePath/leading_slash1493=== PAUSE TestIsValidCachePath/leading_slash1494=== RUN TestIsValidCachePath/wrong_extension1495=== PAUSE TestIsValidCachePath/wrong_extension1496=== RUN TestIsValidCachePath/short_hash1497=== PAUSE TestIsValidCachePath/short_hash1498=== CONT TestClaim_FailWakesWaitersButIsNotRemembered14992026/09/07 19:37:17 INFO Completed upload id=215002026/09/07 19:37:17 WARN claim: cannot clear write deadline error="feature not supported"1501--- PASS: TestClaim_BuildWaitComplete (2.57s)1502=== CONT TestClaim_TwoInstances1503--- PASS: TestReadProxyConditionalGet (2.27s)1504=== CONT TestParseSingleRange1505=== RUN TestParseSingleRange/none1506=== PAUSE TestParseSingleRange/none1507=== RUN TestParseSingleRange/unknown_unit1508=== PAUSE TestParseSingleRange/unknown_unit1509=== RUN TestParseSingleRange/multi-range_ignored1510=== PAUSE TestParseSingleRange/multi-range_ignored1511=== RUN TestParseSingleRange/malformed_no_dash1512=== PAUSE TestParseSingleRange/malformed_no_dash1513=== RUN TestParseSingleRange/malformed_both_empty1514=== PAUSE TestParseSingleRange/malformed_both_empty1515=== RUN TestParseSingleRange/malformed_end_before_start1516=== PAUSE TestParseSingleRange/malformed_end_before_start1517=== RUN TestParseSingleRange/closed1518=== PAUSE TestParseSingleRange/closed1519=== RUN TestParseSingleRange/open-ended1520=== PAUSE TestParseSingleRange/open-ended1521=== RUN TestParseSingleRange/end_clamped_to_size1522=== PAUSE TestParseSingleRange/end_clamped_to_size1523=== RUN TestParseSingleRange/suffix1524=== PAUSE TestParseSingleRange/suffix1525=== RUN TestParseSingleRange/suffix_exceeds_size1526=== PAUSE TestParseSingleRange/suffix_exceeds_size1527=== RUN TestParseSingleRange/single_byte1528=== PAUSE TestParseSingleRange/single_byte1529=== RUN TestParseSingleRange/start_past_EOF1530=== PAUSE TestParseSingleRange/start_past_EOF1531=== RUN TestParseSingleRange/start_far_past_EOF1532=== PAUSE TestParseSingleRange/start_far_past_EOF1533=== CONT TestClaim_HolderDisconnectKeepsClaim15342026-09-07 19:37:17.349 UTC [1159] ERROR: relation "goose_db_version" does not exist at character 3615352026-09-07 19:37:17.349 UTC [1159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15362026-09-07 19:37:17.354 UTC [1160] ERROR: relation "goose_db_version" does not exist at character 3615372026-09-07 19:37:17.354 UTC [1160] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15382026/09/07 19:37:17 OK 20241026095416_initial_model.sql (11.36ms)15392026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)15402026/09/07 19:37:17 OK 20241026095416_initial_model.sql (9.51ms)15412026/09/07 19:37:17 OK 20251218171726_add_pins.sql (3.03ms)15422026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)15432026-09-07 19:37:17.378 UTC [1161] ERROR: relation "goose_db_version" does not exist at character 3615442026-09-07 19:37:17.378 UTC [1161] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15452026/09/07 19:37:17 OK 20251218171726_add_pins.sql (3.83ms)15462026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)15472026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (5.47ms)15482026/09/07 19:37:17 OK 20260905000000_add_claims.sql (5.4ms)15492026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000015502026/09/07 19:37:17 OK 1_commit_pending_closure.sql (3.43ms)15512026/09/07 19:37:17 OK 20260905000000_add_claims.sql (3.74ms)15522026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000015532026/09/07 19:37:17 OK 2_object_stats_trigger.sql (948.71µs)15542026/09/07 19:37:17 goose: up to current file version: 215552026/09/07 19:37:17 OK 1_commit_pending_closure.sql (1.83ms)15562026/09/07 19:37:17 OK 2_object_stats_trigger.sql (7.82ms)15572026/09/07 19:37:17 goose: up to current file version: 215582026/09/07 19:37:17 OK 20241026095416_initial_model.sql (14.67ms)15592026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)15602026/09/07 19:37:17 OK 20251218171726_add_pins.sql (4.65ms)15612026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)15622026/09/07 19:37:17 OK 20260905000000_add_claims.sql (3.84ms)15632026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000015642026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.92ms)15652026/09/07 19:37:17 OK 2_object_stats_trigger.sql (936.39µs)15662026/09/07 19:37:17 goose: up to current file version: 21567--- PASS: TestService_ReadScope_PublicByDefault (2.32s)1568=== CONT TestResurrectedObjectNotDeleted1569--- PASS: TestReadProxyHead (2.34s)1570=== CONT TestOrphanedObjectsGCStressTest15712026-09-07 19:37:17.502 UTC [1166] ERROR: relation "goose_db_version" does not exist at character 3615722026-09-07 19:37:17.502 UTC [1166] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/09/07 19:37:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15742026/09/07 19:37:17 OK 20241026095416_initial_model.sql (13.41ms)15752026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)15762026/09/07 19:37:17 OK 20251218171726_add_pins.sql (4.19ms)15772026/09/07 19:37:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLjljMzY4MWU5LTBiMzItNDRlOC05M2FlLWRkMTUzN2U5ODc5Y3gxNzg4ODA5ODM1NTM2OTMxNjM2 parts=121578--- PASS: TestRedundantMultipartUpload (2.92s)1579=== CONT TestClaim_TooManyStreams15802026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)15812026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.07ms)15822026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000015832026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.17ms)15842026/09/07 19:37:17 OK 2_object_stats_trigger.sql (1.34ms)15852026/09/07 19:37:17 goose: up to current file version: 21586--- PASS: TestReadProxyInvalidPath (2.12s)1587=== CONT TestNARDeduplicationMetadataUploadBug15882026-09-07 19:37:17.553 UTC [1169] ERROR: relation "goose_db_version" does not exist at character 3615892026-09-07 19:37:17.553 UTC [1169] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1590=== RUN TestService_RequireScope_OIDC/builder_may_write1591=== PAUSE TestService_RequireScope_OIDC/builder_may_write1592=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1593=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1594=== RUN TestService_RequireScope_OIDC/ops_may_admin1595=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1596=== RUN TestService_RequireScope_OIDC/ops_may_not_write1597=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1598=== RUN TestService_RequireScope_OIDC/reader_may_not_write1599=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1600=== RUN TestService_RequireScope_OIDC/static_token_may_admin1601=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1602=== RUN TestService_RequireScope_OIDC/static_token_may_write1603=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1604=== RUN TestService_RequireScope_OIDC/reader_may_read1605=== PAUSE TestService_RequireScope_OIDC/reader_may_read1606=== RUN TestService_RequireScope_OIDC/writer_implies_read1607=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1608=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1609=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1610=== CONT TestClaim_StaleHeartbeatStolen16112026/09/07 19:37:17 OK 20241026095416_initial_model.sql (13.42ms)16122026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)16132026/09/07 19:37:17 OK 20251218171726_add_pins.sql (7.42ms)16142026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (5.7ms)16152026/09/07 19:37:17 OK 20260905000000_add_claims.sql (8.71ms)16162026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000016172026/09/07 19:37:17 OK 1_commit_pending_closure.sql (6.43ms)16182026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.38ms)16192026/09/07 19:37:17 goose: up to current file version: 216202026-09-07 19:37:17.617 UTC [1174] ERROR: relation "goose_db_version" does not exist at character 3616212026-09-07 19:37:17.617 UTC [1174] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026-09-07 19:37:17.632 UTC [1175] ERROR: relation "goose_db_version" does not exist at character 3616232026-09-07 19:37:17.632 UTC [1175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1624=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1625=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1626=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1627=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1628=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1629=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1630=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1631=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1632=== CONT TestCreatePendingClosureRejectsOversizedNAR16332026/09/07 19:37:17 INFO Received uploads request method=POST path=/api/pending_closures1634--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1635=== CONT TestCacheConfigHandlerMaxNarSize1636--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1637=== CONT TestMultipartCleanup16382026/09/07 19:37:17 OK 20241026095416_initial_model.sql (11.88ms)16392026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)16402026/09/07 19:37:17 OK 20251218171726_add_pins.sql (3.72ms)16412026-09-07 19:37:17.644 UTC [1177] ERROR: relation "goose_db_version" does not exist at character 3616422026-09-07 19:37:17.644 UTC [1177] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16432026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)16442026/09/07 19:37:17 OK 20241026095416_initial_model.sql (10.46ms)16452026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)16462026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.37ms)16472026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000016482026/09/07 19:37:17 OK 1_commit_pending_closure.sql (3.41ms)16492026/09/07 19:37:17 OK 20251218171726_add_pins.sql (6.91ms)16502026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.98ms)16512026/09/07 19:37:17 goose: up to current file version: 216522026/09/07 19:37:17 OK 20241026095416_initial_model.sql (10.94ms)16532026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)16542026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (5.11ms)1655--- PASS: TestReadProxy404 (2.15s)1656=== CONT TestMetricsInventory16572026/09/07 19:37:17 OK 20251218171726_add_pins.sql (4.13ms)16582026/09/07 19:37:17 OK 20260905000000_add_claims.sql (5.45ms)16592026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000016602026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)16612026/09/07 19:37:17 OK 1_commit_pending_closure.sql (3.53ms)16622026/09/07 19:37:17 OK 2_object_stats_trigger.sql (1.5ms)16632026/09/07 19:37:17 goose: up to current file version: 216642026/09/07 19:37:17 OK 20260905000000_add_claims.sql (3.98ms)16652026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000016662026/09/07 19:37:17 OK 1_commit_pending_closure.sql (4.45ms)16672026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.25ms)16682026/09/07 19:37:17 goose: up to current file version: 21669--- PASS: TestService_ReadAuthMiddleware (2.14s)1670=== CONT TestService_healthCheckHandler16712026-09-07 19:37:17.711 UTC [1183] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-07 19:37:17.711 UTC [1183] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026/09/07 19:37:17 INFO Received uploads request method=POST path=/api/pending_closures16742026/09/07 19:37:17 OK 20241026095416_initial_model.sql (12.46ms)16752026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)16762026/09/07 19:37:17 OK 20251218171726_add_pins.sql (3.85ms)16772026-09-07 19:37:17.740 UTC [1185] ERROR: relation "goose_db_version" does not exist at character 3616782026-09-07 19:37:17.740 UTC [1185] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16792026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)16802026/09/07 19:37:17 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16812026/09/07 19:37:17 WARN mTLS auth: bound subjects configured but subject DN unavailable16822026/09/07 19:37:17 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1683--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.82s)1684=== CONT TestOrphanedObjectsGC16852026/09/07 19:37:17 OK 20260905000000_add_claims.sql (3.63ms)16862026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000016872026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.97ms)16882026/09/07 19:37:17 OK 2_object_stats_trigger.sql (1.71ms)16892026/09/07 19:37:17 goose: up to current file version: 216902026/09/07 19:37:17 OK 20241026095416_initial_model.sql (15.18ms)16912026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)16922026/09/07 19:37:17 OK 20251218171726_add_pins.sql (3.91ms)16932026-09-07 19:37:17.771 UTC [1188] ERROR: relation "goose_db_version" does not exist at character 3616942026-09-07 19:37:17.771 UTC [1188] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16952026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)16962026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.73ms)16972026/09/07 19:37:17 goose: successfully migrated database to version: 202609050000001698--- PASS: TestReadProxyNarStreaming (1.83s)1699=== CONT TestServerTLSConfig1700=== RUN TestServerTLSConfig/no_client_CA1701=== PAUSE TestServerTLSConfig/no_client_CA1702=== RUN TestServerTLSConfig/missing_CA_file1703=== PAUSE TestServerTLSConfig/missing_CA_file1704=== RUN TestServerTLSConfig/not_a_PEM_file1705=== PAUSE TestServerTLSConfig/not_a_PEM_file1706=== CONT TestService_readinessHandler17072026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.88ms)17082026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.06ms)17092026/09/07 19:37:17 goose: up to current file version: 217102026/09/07 19:37:17 OK 20241026095416_initial_model.sql (10.44ms)17112026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)17122026/09/07 19:37:17 OK 20251218171726_add_pins.sql (4.59ms)17132026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (7.09ms)17142026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.43ms)17152026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000017162026/09/07 19:37:17 OK 1_commit_pending_closure.sql (3.31ms)17172026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.21ms)17182026/09/07 19:37:17 goose: up to current file version: 21719--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.77s)1720=== CONT TestGenerateLandingPage1721--- PASS: TestGenerateLandingPage (0.01s)1722=== CONT TestService_NativeMTLS17232026-09-07 19:37:17.845 UTC [1193] ERROR: relation "goose_db_version" does not exist at character 3617242026-09-07 19:37:17.845 UTC [1193] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17252026-09-07 19:37:17.864 UTC [1212] ERROR: relation "goose_db_version" does not exist at character 3617262026-09-07 19:37:17.864 UTC [1212] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17272026/09/07 19:37:17 OK 20241026095416_initial_model.sql (11.3ms)17282026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)17292026/09/07 19:37:17 OK 20251218171726_add_pins.sql (4.72ms)17302026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)17312026/09/07 19:37:17 OK 20241026095416_initial_model.sql (11.8ms)17322026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)17332026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.52ms)17342026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000017352026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.85ms)17362026/09/07 19:37:17 OK 20251218171726_add_pins.sql (5.41ms)17372026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.27ms)17382026/09/07 19:37:17 goose: up to current file version: 217392026/09/07 19:37:17 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=017402026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (5.64ms)1741=== NAME TestClientCADerivations1742 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations667519492/001/store/k1rd6hirm9gspm5n3hwwnmm5a74mpdrd-ca-test17432026/09/07 19:37:17 OK 20260905000000_add_claims.sql (9ms)17442026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000017452026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.01ms)17462026/09/07 19:37:17 OK 2_object_stats_trigger.sql (934.21µs)17472026/09/07 19:37:17 goose: up to current file version: 217482026-09-07 19:37:17.918 UTC [1231] ERROR: relation "goose_db_version" does not exist at character 3617492026-09-07 19:37:17.918 UTC [1231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1750--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.13s)1751=== CONT TestObjectStatsTrigger17522026/09/07 19:37:17 OK 20241026095416_initial_model.sql (11.48ms)17532026/09/07 19:37:17 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)17542026/09/07 19:37:17 WARN readiness check failed error="closed pool"1755--- PASS: TestService_readinessHandler (0.16s)1756=== CONT TestResolveDBConnectionString/flag_wins1757=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1758=== CONT TestResolveDBConnectionString/missing_file_is_an_error1759=== CONT TestResolveDBConnectionString/file_when_flag_empty1760=== CONT TestProxyWriteTimeout/narinfo1761=== CONT TestResolveDBConnectionString/nothing_configured1762=== CONT TestProxyWriteTimeout/unknown_size1763=== CONT TestProxyWriteTimeout/10_GiB_nar1764=== CONT TestProxyWriteTimeout/1_GiB_nar1765--- PASS: TestProxyWriteTimeout (0.06s)1766 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1767 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1768 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1769 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1770=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17712026/09/07 19:37:17 INFO Received uploads request method=POST path=/1772=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1773--- PASS: TestResolveDBConnectionString (0.06s)1774 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1775 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1776 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1777 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1778 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)17792026/09/07 19:37:17 OK 20251218171726_add_pins.sql (4.01ms)17802026/09/07 19:37:17 INFO Received complete multipart upload request method=POST path=/1781=== NAME TestClientCADerivations1782 client_ca_test.go:139: Found 1 dependencies (including self)1783=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17842026/09/07 19:37:17 INFO Received uploads request method=POST path=/1785=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17862026/09/07 19:37:17 INFO Received request for more parts method=POST path=/1787--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)1788 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1789 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1790 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1791 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1792=== CONT TestIsValidUploadKey/traversal1793=== CONT TestIsValidUploadKey/narinfo1794=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1795=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1796=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1797=== CONT TestIsValidUploadKey/index.html1798=== CONT TestIsValidUploadKey/nix-cache-info1799=== CONT TestIsValidUploadKey/realisation_plus_in_output1800=== CONT TestIsValidUploadKey/realisation1801=== CONT TestIsValidUploadKey/build_log_equals1802=== CONT TestIsValidUploadKey/build_log_question_mark1803=== CONT TestIsValidUploadKey/build_log_plus_in_name1804=== CONT TestIsValidUploadKey/build_log_home-manager_file1805=== CONT TestIsValidUploadKey/build_log1806=== CONT TestIsValidUploadKey/listing1807=== CONT TestIsValidUploadKey/nar_plain1808=== CONT TestIsValidUploadKey/nar_xz1809=== CONT TestIsValidUploadKey/nar_zst1810=== CONT TestIsValidUploadKey/unknown_type1811=== CONT TestIsValidUploadKey/absolute1812=== CONT TestIsValidUploadKey/traversal_nar1813=== CONT TestIsValidUploadKey/empty_key1814--- PASS: TestIsValidUploadKey (0.06s)1815 --- PASS: TestIsValidUploadKey/traversal (0.00s)1816 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1817 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1818 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1819 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1820 --- PASS: TestIsValidUploadKey/index.html (0.00s)1821 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1822 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1823 --- PASS: TestIsValidUploadKey/realisation (0.00s)1824 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1825 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1826 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1827 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1828 --- PASS: TestIsValidUploadKey/build_log (0.00s)1829 --- PASS: TestIsValidUploadKey/listing (0.00s)1830 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1831 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1832 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1833 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1834 --- PASS: TestIsValidUploadKey/absolute (0.00s)1835 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1836 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1837=== CONT TestClientErrorHandling/InvalidStorePath18382026/09/07 19:37:17 OK 20260628120000_add_object_size_and_stats.sql (10.24ms)18392026/09/07 19:37:17 OK 20260905000000_add_claims.sql (4.63ms)18402026/09/07 19:37:17 goose: successfully migrated database to version: 2026090500000018412026/09/07 19:37:17 OK 1_commit_pending_closure.sql (2.81ms)18422026/09/07 19:37:17 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=018432026/09/07 19:37:17 OK 2_object_stats_trigger.sql (2.3ms)18442026/09/07 19:37:17 goose: up to current file version: 218452026-09-07 19:37:18.008 UTC [1272] ERROR: relation "goose_db_version" does not exist at character 3618462026-09-07 19:37:18.008 UTC [1272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1847--- PASS: TestReadProxyNarinfo (1.13s)1848=== CONT TestClientErrorHandling/ServerNotAvailable18492026/09/07 19:37:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18502026/09/07 19:37:18 OK 20241026095416_initial_model.sql (10.41ms)18512026/09/07 19:37:18 OK 20251210153512_drop_unused_gin_index.sql (1.39ms)18522026/09/07 19:37:18 OK 20251218171726_add_pins.sql (3.62ms)18532026/09/07 19:37:18 INFO Received uploads request method=POST path=/api/pending_closures18542026-09-07 19:37:18.032 UTC [1292] ERROR: relation "goose_db_version" does not exist at character 3618552026-09-07 19:37:18.032 UTC [1292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18562026/09/07 19:37:18 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)18572026/09/07 19:37:18 OK 20260905000000_add_claims.sql (2.79ms)18582026/09/07 19:37:18 goose: successfully migrated database to version: 2026090500000018592026/09/07 19:37:18 OK 1_commit_pending_closure.sql (2.22ms)18602026/09/07 19:37:18 OK 2_object_stats_trigger.sql (820.85µs)18612026/09/07 19:37:18 goose: up to current file version: 218622026/09/07 19:37:18 OK 20241026095416_initial_model.sql (8.99ms)18632026/09/07 19:37:18 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)18642026/09/07 19:37:18 OK 20251218171726_add_pins.sql (2.94ms)18652026/09/07 19:37:18 INFO Received uploads request method=POST path=/api/pending_closures18662026/09/07 19:37:18 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)18672026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"18682026/09/07 19:37:18 OK 20260905000000_add_claims.sql (3.17ms)18692026/09/07 19:37:18 goose: successfully migrated database to version: 2026090500000018702026/09/07 19:37:18 OK 1_commit_pending_closure.sql (1.87ms)18712026/09/07 19:37:18 OK 2_object_stats_trigger.sql (1.92ms)18722026/09/07 19:37:18 goose: up to current file version: 218732026/09/07 19:37:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18742026/09/07 19:37:18 INFO Uploading k1rd6hirm9gspm5n3hwwnmm5a74mpdrd-ca-test (144B)18752026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"18762026/09/07 19:37:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18772026/09/07 19:37:18 WARN Failed to register uploaded object key=log/rj4mw0wrwicyy5hvvpd4js4b42imq0n8-ca-test.drv error="server returned 404: 404 page not found\n"1878--- PASS: TestClaim_FailWithoutKindReleases (1.00s)1879=== CONT TestClientErrorHandling/InvalidAuthToken18802026/09/07 19:37:18 WARN Failed to register uploaded object key=k1rd6hirm9gspm5n3hwwnmm5a74mpdrd.ls error="server returned 404: 404 page not found\n"18812026/09/07 19:37:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18822026/09/07 19:37:18 INFO Signed narinfos id=1 count=118832026/09/07 19:37:18 INFO Uploading 1 narinfos18842026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"18852026/09/07 19:37:18 WARN Failed to register uploaded object key=k1rd6hirm9gspm5n3hwwnmm5a74mpdrd.narinfo error="server returned 404: 404 page not found\n"18862026/09/07 19:37:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18872026/09/07 19:37:18 INFO Completed upload id=118882026/09/07 19:37:18 INFO Upload complete. (111ms)18892026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"18902026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"1891--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (0.84s)1892=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18932026/09/07 19:37:18 INFO Received uploads request method=POST path=/1894=== NAME TestClientCADerivations1895 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations667519492/001/store/k1rd6hirm9gspm5n3hwwnmm5a74mpdrd-ca-test1896 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1897 Compression: zstd1898 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1899 NarSize: 1441900 References: 1901 Deriver: /build/TestClientCADerivations667519492/001/store/rj4mw0wrwicyy5hvvpd4js4b42imq0n8-ca-test.drv1902 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1903 client_ca_test.go:185: Checking for realisation files in S3...1904 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1905 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19062026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19072026/09/07 19:37:18 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19082026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19092026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19102026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19112026/09/07 19:37:18 INFO Received uploads request method=POST path=/api/pending_closures19122026-09-07 19:37:18.145 UTC [1390] ERROR: relation "goose_db_version" does not exist at character 3619132026-09-07 19:37:18.145 UTC [1390] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19142026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19152026/09/07 19:37:18 OK 20241026095416_initial_model.sql (10.29ms)19162026/09/07 19:37:18 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)19172026/09/07 19:37:18 OK 20251218171726_add_pins.sql (3.77ms)19182026/09/07 19:37:18 OK 20260628120000_add_object_size_and_stats.sql (2.48ms)19192026/09/07 19:37:18 OK 20260905000000_add_claims.sql (2.77ms)19202026/09/07 19:37:18 goose: successfully migrated database to version: 2026090500000019212026/09/07 19:37:18 OK 1_commit_pending_closure.sql (2.14ms)19222026/09/07 19:37:18 OK 2_object_stats_trigger.sql (1.68ms)19232026/09/07 19:37:18 goose: up to current file version: 21924--- PASS: TestResurrectedObjectNotDeleted (0.80s)1925=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19262026/09/07 19:37:18 INFO Received complete multipart upload request method=POST path=/19272026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"1928--- PASS: TestClaim_TooManyStreams (0.69s)1929=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19302026/09/07 19:37:18 INFO Received request for more parts method=POST path=/19312026/09/07 19:37:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.646841ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19322026/09/07 19:37:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19332026/09/07 19:37:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLmFlMDcxM2VjLTg5MzktNDAwMC05ZTM3LWZiNDc3ODYyODUyNHgxNzg4ODA5ODM3NzMyNzE0MjYy parts=1019342026/09/07 19:37:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19352026/09/07 19:37:18 INFO Completed upload id=119362026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19372026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"19382026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"1939--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (2.52s)1940=== CONT TestCacheConfigHandler/full_config,_no_issuer1941=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1942=== CONT TestCacheConfigHandler/no_signing_keys1943=== CONT TestCacheConfigHandler/no_cache_url_configured1944--- PASS: TestCacheConfigHandler (0.00s)1945 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1946 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1947 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1948 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1949=== CONT TestIsValidCachePath/narinfo1950=== CONT TestIsValidCachePath/invalid_char_u1951=== CONT TestIsValidCachePath/invalid_char_e1952=== CONT TestIsValidCachePath/traversal_in_middle1953=== CONT TestIsValidCachePath/traversal_parent1954=== CONT TestIsValidCachePath/index.html1955=== CONT TestIsValidCachePath/nix-cache-info1956=== CONT TestIsValidCachePath/random_path1957=== CONT TestIsValidCachePath/realisation1958=== CONT TestIsValidCachePath/log1959=== CONT TestIsValidCachePath/ls1960=== CONT TestIsValidCachePath/nar_uncompressed1961=== CONT TestIsValidCachePath/nar_bz21962=== CONT TestIsValidCachePath/nar_xz1963=== CONT TestIsValidCachePath/nar_zst1964=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1965=== CONT TestIsValidCachePath/leading_slash1966=== CONT TestIsValidCachePath/short_hash1967=== CONT TestIsValidCachePath/empty1968=== CONT TestIsValidCachePath/wrong_extension1969--- PASS: TestIsValidCachePath (0.00s)1970 --- PASS: TestIsValidCachePath/narinfo (0.00s)1971 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1972 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1973 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1974 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1975 --- PASS: TestIsValidCachePath/index.html (0.00s)1976 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1977 --- PASS: TestIsValidCachePath/random_path (0.00s)1978 --- PASS: TestIsValidCachePath/realisation (0.00s)1979 --- PASS: TestIsValidCachePath/log (0.00s)1980 --- PASS: TestIsValidCachePath/ls (0.00s)1981 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1982 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1983 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1984 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1985 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1986 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1987 --- PASS: TestIsValidCachePath/short_hash (0.00s)1988 --- PASS: TestIsValidCachePath/empty (0.00s)1989 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1990=== CONT TestParseSingleRange/none1991=== CONT TestParseSingleRange/open-ended1992=== CONT TestParseSingleRange/start_far_past_EOF1993=== CONT TestParseSingleRange/start_past_EOF1994=== CONT TestParseSingleRange/single_byte1995=== CONT TestParseSingleRange/suffix_exceeds_size1996=== CONT TestParseSingleRange/suffix1997=== CONT TestParseSingleRange/end_clamped_to_size1998=== CONT TestParseSingleRange/malformed_both_empty1999=== CONT TestParseSingleRange/closed2000=== CONT TestParseSingleRange/malformed_end_before_start2001=== CONT TestParseSingleRange/multi-range_ignored2002=== CONT TestParseSingleRange/malformed_no_dash2003=== CONT TestParseSingleRange/unknown_unit2004--- PASS: TestParseSingleRange (0.00s)2005 --- PASS: TestParseSingleRange/none (0.00s)2006 --- PASS: TestParseSingleRange/open-ended (0.00s)2007 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2008 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2009 --- PASS: TestParseSingleRange/single_byte (0.00s)2010 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2011 --- PASS: TestParseSingleRange/suffix (0.00s)2012 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2013 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2014 --- PASS: TestParseSingleRange/closed (0.00s)2015 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2016 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2017 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2018 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2019=== CONT TestService_RequireScope_OIDC/builder_may_write20202026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"2021--- PASS: TestClaim_StaleHeartbeatStolen (0.73s)2022=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2023=== CONT TestService_RequireScope_OIDC/writer_implies_read20242026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[write]2025=== CONT TestService_RequireScope_OIDC/reader_may_read20262026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[write]2027=== CONT TestService_RequireScope_OIDC/static_token_may_write2028=== CONT TestService_RequireScope_OIDC/static_token_may_admin2029=== CONT TestService_RequireScope_OIDC/reader_may_not_write20302026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[read]2031=== CONT TestService_RequireScope_OIDC/ops_may_not_write20322026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[read]2033=== CONT TestService_RequireScope_OIDC/ops_may_admin20342026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[admin]2035=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20362026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[admin]2037=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20382026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[write]2039=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20402026/09/07 19:37:18 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]2041=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2042--- PASS: TestService_RequireScope_OIDC (2.23s)2043 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2044 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2045 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2046 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2047 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20532026/09/07 19:37:18 INFO OIDC auth successful provider=test scopes=[write]2054=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2055=== CONT TestServerTLSConfig/no_client_CA2056=== CONT TestServerTLSConfig/missing_CA_file2057=== CONT TestServerTLSConfig/not_a_PEM_file2058=== NAME TestNARDeduplicationMetadataUploadBug2059 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1398199028/001/store/v6hi9biwk5lpspf4qwfxspla97gw3hy4-file1.txt20602026/09/07 19:37:18 WARN Authentication failed token_preview=eyJhbGciOi...mJFqb-7gzQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2061--- PASS: TestServerTLSConfig (0.00s)2062 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2063 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2064 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2065--- PASS: TestService_AuthMiddleware_OIDC (2.15s)2066 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2067 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2068 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2069 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2070=== NAME TestClientCADerivations2071 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2072 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2073 error: binary cache 's3://bucket39?endpoint=http://localhost:34509®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations667519492/001/store'2074 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12075--- PASS: TestClientCADerivations (2.28s)20762026/09/07 19:37:18 INFO Received uploads request method=POST path=/api/pending_closures2077--- PASS: TestMetricsInventory (0.71s)20782026/09/07 19:37:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2079--- PASS: TestService_healthCheckHandler (0.69s)20802026/09/07 19:37:18 INFO Received uploads request method=POST path=/api/pending_closures20812026/09/07 19:37:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20822026/09/07 19:37:18 INFO Uploading v6hi9biwk5lpspf4qwfxspla97gw3hy4-file1.txt (160B)20832026/09/07 19:37:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20842026/09/07 19:37:18 WARN Failed to register uploaded object key=v6hi9biwk5lpspf4qwfxspla97gw3hy4.ls error="server returned 404: 404 page not found\n"20852026/09/07 19:37:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20862026/09/07 19:37:18 INFO Received cleanup request method=DELETE path=/api/pending_closures20872026/09/07 19:37:18 INFO Signed narinfos id=1 count=120882026/09/07 19:37:18 INFO Uploading 1 narinfos20892026/09/07 19:37:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.41265ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20902026/09/07 19:37:18 INFO Aborted multipart uploads count=120912026/09/07 19:37:18 WARN Failed to register uploaded object key=v6hi9biwk5lpspf4qwfxspla97gw3hy4.narinfo error="server returned 404: 404 page not found\n"20922026/09/07 19:37:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2093--- PASS: TestMultipartCleanup (0.83s)20942026/09/07 19:37:18 INFO Completed upload id=120952026/09/07 19:37:18 INFO Upload complete. (130ms)2096=== NAME TestNARDeduplicationMetadataUploadBug2097 metadata_upload_test.go:54: Retrieved narinfo from S3:2098 StorePath: /build/TestNARDeduplicationMetadataUploadBug1398199028/001/store/v6hi9biwk5lpspf4qwfxspla97gw3hy4-file1.txt2099 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2100 Compression: zstd2101 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2102 NarSize: 1602103 References: 2104 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2105 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2106 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2107 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2108 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1398199028/001/store/gvyhavr6f0cx2zf903n38rnr6b3ri0av-file2.txt21092026/09/07 19:37:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21102026/09/07 19:37:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLmNhZTY3M2Y4LTE1YTYtNDc2Yi1hMmI1LTkzZWRjYjVhYjc0MXgxNzg4ODA5ODM4MDQ0MzQ2MjA2 parts=1021112026/09/07 19:37:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21122026/09/07 19:37:18 INFO Completed upload id=121132026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"21142026/09/07 19:37:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21152026/09/07 19:37:18 INFO Aborted multipart uploads count=021162026/09/07 19:37:18 WARN Force mode enabled - objects will be deleted immediately without grace period21172026/09/07 19:37:18 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=021182026/09/07 19:37:18 INFO Vacuumed table table=pending_closures21192026/09/07 19:37:18 INFO Vacuumed table table=pending_objects21202026/09/07 19:37:18 INFO Vacuumed table table=multipart_uploads21212026/09/07 19:37:18 INFO Vacuumed table table=closures21222026/09/07 19:37:18 INFO Vacuumed table table=objects2123--- PASS: TestClaim_InputsTouched (1.72s)21242026/09/07 19:37:18 INFO Received uploads request method=POST path=/api/pending_closures21252026/09/07 19:37:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21262026/09/07 19:37:18 WARN Failed to register uploaded object key=gvyhavr6f0cx2zf903n38rnr6b3ri0av.ls error="server returned 404: 404 page not found\n"21272026/09/07 19:37:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21282026/09/07 19:37:18 INFO Signed narinfos id=2 count=121292026/09/07 19:37:18 INFO Uploading 1 narinfos21302026/09/07 19:37:18 WARN Failed to register uploaded object key=gvyhavr6f0cx2zf903n38rnr6b3ri0av.narinfo error="server returned 404: 404 page not found\n"21312026/09/07 19:37:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21322026/09/07 19:37:18 INFO Completed upload id=221332026/09/07 19:37:18 INFO Upload complete. (90ms)2134=== NAME TestNARDeduplicationMetadataUploadBug2135 metadata_upload_test.go:76: Retrieved narinfo from S3:2136 StorePath: /build/TestNARDeduplicationMetadataUploadBug1398199028/001/store/gvyhavr6f0cx2zf903n38rnr6b3ri0av-file2.txt2137 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2138 Compression: zstd2139 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2140 NarSize: 1602141 References: 2142 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2143 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2144 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2145 {"version":1,"root":{"type":"regular","size":44}}2146--- PASS: TestNARDeduplicationMetadataUploadBug (1.10s)21472026/09/07 19:37:18 WARN claim: cannot clear write deadline error="feature not supported"21482026/09/07 19:37:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"21492026/09/07 19:37:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2150--- PASS: TestService_NativeMTLS (0.96s)2151--- PASS: TestObjectStatsTrigger (0.91s)21522026/09/07 19:37:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=853.472204ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21532026/09/07 19:37:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21542026/09/07 19:37:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21552026/09/07 19:37:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21562026/09/07 19:37:19 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=OWEwMGNjZjItNzQ0My00Y2RkLWIzYmYtZDY5YmZiNmIxMWJjLmZhNzEzOGZlLTQ2OTgtNDE5NS1hMWYzLWVhYzMxODU3N2ExMHgxNzg4ODA5ODM4MTQ3NTg3NTM1 parts=1021572026/09/07 19:37:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21582026/09/07 19:37:19 INFO Signed narinfos id=1 count=121592026/09/07 19:37:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21602026/09/07 19:37:19 INFO Completed upload id=12161--- PASS: TestClaim_TwoInstances (1.83s)2162=== NAME TestOrphanedObjectsGC2163 orphaned_objects_gc_test.go:290: GC Test Summary:2164 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2165 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2166 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2167 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2168 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2169--- PASS: TestOrphanedObjectsGC (1.35s)21702026/09/07 19:37:19 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=021712026/09/07 19:37:19 INFO Vacuumed table table=pending_closures21722026/09/07 19:37:19 INFO Vacuumed table table=pending_objects21732026/09/07 19:37:19 INFO Vacuumed table table=multipart_uploads21742026/09/07 19:37:19 INFO Vacuumed table table=closures21752026/09/07 19:37:19 INFO Vacuumed table table=objects2176--- PASS: TestClaim_StreamsThroughServer (2.62s)2177--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2178 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.11s)2179 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.11s)2180 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.61s)21812026/09/07 19:37:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.519611536s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21822026/09/07 19:37:19 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=021832026/09/07 19:37:19 INFO Vacuumed table table=pending_closures21842026/09/07 19:37:19 INFO Vacuumed table table=pending_objects21852026/09/07 19:37:19 INFO Vacuumed table table=multipart_uploads21862026/09/07 19:37:19 INFO Vacuumed table table=closures21872026/09/07 19:37:19 INFO Vacuumed table table=objects2188=== NAME TestOrphanedObjectsGCStressTest2189 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains21902026/09/07 19:37:19 WARN Rate limiter enabled after throttle name=s3-test rate=521912026/09/07 19:37:19 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2192=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2193 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102194 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002195--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.26s)2196=== NAME TestOrphanedObjectsGCStressTest2197 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21982026/09/07 19:37:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02199=== NAME TestPinProtectsFromGC2200 client_integration_test.go:711: Pin successfully protected closure from garbage collection2201--- PASS: TestPinProtectsFromGC (5.35s)22022026/09/07 19:37:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02203=== NAME TestClientIntegration2204 client_integration_test.go:304: Objects in database after GC:2205 client_integration_test.go:304: Successfully deleted all objects with GC --force2206--- PASS: TestClientIntegration (5.36s)2207=== NAME TestOrphanedObjectsGCStressTest2208 orphaned_objects_gc_test.go:509: Stress test completed successfully:2209 orphaned_objects_gc_test.go:510: - Active objects preserved: 202210 orphaned_objects_gc_test.go:511: - Objects deleted: 2102211 orphaned_objects_gc_test.go:512: - Total GC'd: 2102212--- PASS: TestOrphanedObjectsGCStressTest (2.73s)2213--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.37s)22142026/09/07 19:37:21 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"22152026/09/07 19:37:21 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_closures22162026/09/07 19:37:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.549287ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22172026/09/07 19:37:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.16509ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22182026/09/07 19:37:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=792.755373ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22192026/09/07 19:37:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.740903016s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2220--- PASS: TestClientErrorHandling (0.00s)2221 --- PASS: TestClientErrorHandling/InvalidStorePath (0.93s)2222 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.94s)2223 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.50s)2224PASS22252026-09-07 19:37:24.745 UTC [109] LOG: received smart shutdown request22262026-09-07 19:37:24.750 UTC [109] LOG: background worker "logical replication launcher" (PID 119) exited with exit code 122272026-09-07 19:37:24.767 UTC [114] LOG: shutting down22282026-09-07 19:37:24.767 UTC [114] LOG: checkpoint starting: shutdown immediate22292026-09-07 19:37:25.814 UTC [114] LOG: checkpoint complete: wrote 11780 buffers (71.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 17 recycled; write=0.235 s, sync=0.800 s, total=1.048 s; sync files=21000, longest=0.002 s, average=0.001 s; distance=282890 kB, estimate=282890 kB; lsn=0/12BA88B0, redo lsn=0/12BA88B022302026-09-07 19:37:25.930 UTC [109] LOG: database system is shut down2231Running OIDC tests...2232=== RUN TestGlobMatch2233=== PAUSE TestGlobMatch2234=== RUN TestAudienceForIssuer2235=== PAUSE TestAudienceForIssuer2236=== RUN TestValidateToken_ValidToken2237=== PAUSE TestValidateToken_ValidToken2238=== RUN TestValidateToken_WrongAudience2239=== PAUSE TestValidateToken_WrongAudience2240=== RUN TestValidateToken_Expired2241=== PAUSE TestValidateToken_Expired2242=== RUN TestValidateToken_BoundClaimsMismatch2243=== PAUSE TestValidateToken_BoundClaimsMismatch2244=== RUN TestValidateToken_BoundSubjectMismatch2245=== PAUSE TestValidateToken_BoundSubjectMismatch2246=== RUN TestValidateToken_MultipleProviders2247=== PAUSE TestValidateToken_MultipleProviders2248=== RUN TestValidateToken_NoMatchingProvider2249=== PAUSE TestValidateToken_NoMatchingProvider2250=== RUN TestValidateToken_KubernetesServiceAccount2251=== PAUSE TestValidateToken_KubernetesServiceAccount2252=== RUN TestNewValidator_KubernetesRequiresCA2253=== PAUSE TestNewValidator_KubernetesRequiresCA2254=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2255=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2256=== RUN TestScopes_LegacyProviderDefaultsToWrite2257=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2258=== RUN TestScopes_Rules2259=== PAUSE TestScopes_Rules2260=== RUN TestScopes_ConfigValidation2261=== PAUSE TestScopes_ConfigValidation2262=== CONT TestGlobMatch2263=== CONT TestScopes_LegacyProviderDefaultsToWrite2264=== RUN TestGlobMatch/foo_foo2265=== PAUSE TestGlobMatch/foo_foo2266=== RUN TestGlobMatch/foo_bar2267=== PAUSE TestGlobMatch/foo_bar2268=== RUN TestGlobMatch/*_2269=== PAUSE TestGlobMatch/*_2270=== RUN TestGlobMatch/*_anything2271=== CONT TestValidateToken_WrongAudience2272=== CONT TestValidateToken_ValidToken2273=== CONT TestAudienceForIssuer2274--- PASS: TestAudienceForIssuer (0.00s)2275=== CONT TestValidateToken_BoundSubjectMismatch2276=== CONT TestValidateToken_MultipleProviders2277=== CONT TestValidateToken_BoundClaimsMismatch2278=== CONT TestScopes_ConfigValidation2279=== CONT TestNewValidator_KubernetesRequiresCA2280=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2281=== CONT TestScopes_Rules2282=== CONT TestValidateToken_KubernetesServiceAccount2283=== CONT TestValidateToken_NoMatchingProvider2284=== CONT TestValidateToken_Expired2285=== PAUSE TestGlobMatch/*_anything2286=== RUN TestGlobMatch/foo*_foo2287=== PAUSE TestGlobMatch/foo*_foo2288=== RUN TestGlobMatch/foo*_foobar2289=== PAUSE TestGlobMatch/foo*_foobar2290=== RUN TestGlobMatch/foo*_bar2291=== PAUSE TestGlobMatch/foo*_bar2292=== RUN TestGlobMatch/*bar_bar2293=== PAUSE TestGlobMatch/*bar_bar2294=== RUN TestGlobMatch/*bar_foobar2295=== PAUSE TestGlobMatch/*bar_foobar2296=== RUN TestGlobMatch/*bar_foo2297=== PAUSE TestGlobMatch/*bar_foo2298=== RUN TestGlobMatch/foo*bar_foobar2299=== PAUSE TestGlobMatch/foo*bar_foobar2300=== RUN TestGlobMatch/foo*bar_foo123bar2301=== PAUSE TestGlobMatch/foo*bar_foo123bar2302=== RUN TestGlobMatch/foo*bar_foobarbaz2303=== PAUSE TestGlobMatch/foo*bar_foobarbaz2304=== RUN TestGlobMatch/*/*_foo/bar2305=== PAUSE TestGlobMatch/*/*_foo/bar2306=== RUN TestGlobMatch/*/*_foo2307=== PAUSE TestGlobMatch/*/*_foo2308=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2309=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2310=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02311=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02312=== RUN TestGlobMatch/refs/*/main_refs/heads/main2313=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2314=== RUN TestGlobMatch/fo?_foo2315=== PAUSE TestGlobMatch/fo?_foo2316=== RUN TestGlobMatch/fo?_fo2317=== PAUSE TestGlobMatch/fo?_fo2318=== RUN TestGlobMatch/fo?_fooo2319=== PAUSE TestGlobMatch/fo?_fooo2320--- PASS: TestScopes_ConfigValidation (0.00s)2321=== RUN TestGlobMatch/?oo_foo2322=== PAUSE TestGlobMatch/?oo_foo2323=== RUN TestGlobMatch/?oo_boo2324=== PAUSE TestGlobMatch/?oo_boo2325=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2326=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2327=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2328=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2329=== CONT TestGlobMatch/foo_foo2330=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2331=== CONT TestGlobMatch/foo*bar_foobarbaz2332=== CONT TestGlobMatch/fo?_foo2333=== CONT TestGlobMatch/foo*bar_foo123bar2334=== CONT TestGlobMatch/foo*bar_foobar2335=== CONT TestGlobMatch/*bar_foo2336=== CONT TestGlobMatch/fo?_fooo2337=== CONT TestGlobMatch/fo?_fo2338=== CONT TestGlobMatch/refs/heads/*_refs/heads/main23392026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35235/oidc2340=== CONT TestGlobMatch/*bar_foobar23412026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46605/oidc23422026/09/07 19:37:26 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33759/oidc23432026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44761/oidc23442026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35191/oidc23452026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46689/oidc23462026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44835/oidc2347=== CONT TestGlobMatch/*bar_bar2348=== CONT TestGlobMatch/*/*_foo2349=== CONT TestGlobMatch/foo*_bar2350=== CONT TestGlobMatch/foo*_foobar2351=== CONT TestGlobMatch/foo*_foo2352=== CONT TestGlobMatch/*_anything2353=== CONT TestGlobMatch/*_2354=== CONT TestGlobMatch/foo_bar23552026/09/07 19:37:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44833/oidc2356=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2357=== CONT TestGlobMatch/?oo_boo2358=== CONT TestGlobMatch/?oo_foo2359=== CONT TestGlobMatch/refs/*/main_refs/heads/main2360=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02361=== CONT TestGlobMatch/*/*_foo/bar2362--- PASS: TestGlobMatch (0.01s)2363 --- PASS: TestGlobMatch/foo_foo (0.00s)2364 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2365 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2366 --- PASS: TestGlobMatch/fo?_foo (0.00s)2367 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2368 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2369 --- PASS: TestGlobMatch/*bar_foo (0.00s)2370 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2371 --- PASS: TestGlobMatch/fo?_fo (0.00s)2372 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2373 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2374 --- PASS: TestGlobMatch/*bar_bar (0.00s)2375 --- PASS: TestGlobMatch/foo*_foo (0.00s)2376 --- PASS: TestGlobMatch/foo*_bar (0.00s)2377 --- PASS: TestGlobMatch/*_ (0.00s)2378 --- PASS: TestGlobMatch/*/*_foo (0.00s)2379 --- PASS: TestGlobMatch/*_anything (0.00s)2380 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2381 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2382 --- PASS: TestGlobMatch/?oo_boo (0.00s)2383 --- PASS: TestGlobMatch/foo_bar (0.00s)2384 --- PASS: TestGlobMatch/?oo_foo (0.00s)2385 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2386 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2387 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)23882026/09/07 19:37:26 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38355/oidc23892026/09/07 19:37:26 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323902026/09/07 19:37:26 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33219/oidc2391--- PASS: TestValidateToken_ValidToken (0.01s)2392--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2393--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2394--- PASS: TestValidateToken_Expired (0.01s)2395--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2396--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)23972026/09/07 19:37:26 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:430652398--- PASS: TestValidateToken_WrongAudience (0.02s)2399--- PASS: TestValidateToken_MultipleProviders (0.02s)2400--- PASS: TestScopes_Rules (0.02s)2401--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2402--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)24032026/09/07 19:37:27 http: TLS handshake error from 127.0.0.1:55920: remote error: tls: bad certificate2404--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)2405PASS2406Running hook tests...2407=== RUN TestSendPathsEmpty2408=== PAUSE TestSendPathsEmpty2409=== RUN TestQueueEnqueueAndFetch2410=== PAUSE TestQueueEnqueueAndFetch2411=== RUN TestQueueDeduplication2412=== PAUSE TestQueueDeduplication2413=== RUN TestQueueRemove2414=== PAUSE TestQueueRemove2415=== RUN TestQueueFetchBatchLimit2416=== PAUSE TestQueueFetchBatchLimit2417=== RUN TestQueueRetryMovesToBack2418=== PAUSE TestQueueRetryMovesToBack2419=== RUN TestQueueFetchRemoveLifecycle2420=== PAUSE TestQueueFetchRemoveLifecycle2421=== RUN TestQueueConcurrentWriters2422=== PAUSE TestQueueConcurrentWriters2423=== RUN TestQueueRemoveLargeClosure2424=== PAUSE TestQueueRemoveLargeClosure2425=== RUN TestServerClientIntegration2426=== PAUSE TestServerClientIntegration2427=== RUN TestServerQueueError2428=== PAUSE TestServerQueueError2429=== RUN TestGetListenerSocketActivation2430 server_test.go:214: === RUN TestGetListenerSocketActivation2431 --- PASS: TestGetListenerSocketActivation (0.00s)2432 PASS2433 2434--- PASS: TestGetListenerSocketActivation (0.01s)2435=== RUN TestServerWait2436=== PAUSE TestServerWait2437=== RUN TestDrainIsolatesPoisonPath2438=== PAUSE TestDrainIsolatesPoisonPath2439=== RUN TestRunNotBlockedByPoisonHead2440=== PAUSE TestRunNotBlockedByPoisonHead2441=== RUN TestDrainGivesUpWhenServerDown2442=== PAUSE TestDrainGivesUpWhenServerDown2443=== RUN TestFailedPathPrunedByLaterClosure2444=== PAUSE TestFailedPathPrunedByLaterClosure2445=== RUN TestWorkerUploadsAndRemoves2446=== PAUSE TestWorkerUploadsAndRemoves2447=== RUN TestWorkerSkipsGCdPaths2448=== PAUSE TestWorkerSkipsGCdPaths2449=== RUN TestWorkerPrunesClosureDeps2450=== PAUSE TestWorkerPrunesClosureDeps2451=== RUN TestDrainTimeout2452=== PAUSE TestDrainTimeout2453=== CONT TestSendPathsEmpty2454=== CONT TestDrainGivesUpWhenServerDown2455=== CONT TestServerQueueError2456=== CONT TestWorkerSkipsGCdPaths2457=== CONT TestDrainTimeout2458=== CONT TestWorkerPrunesClosureDeps2459=== CONT TestWorkerUploadsAndRemoves2460--- PASS: TestSendPathsEmpty (0.00s)2461=== CONT TestQueueConcurrentWriters2462=== CONT TestQueueFetchRemoveLifecycle2463=== CONT TestRunNotBlockedByPoisonHead2464=== CONT TestQueueRetryMovesToBack24652026/09/07 19:37:27 ERROR Hook request failed error="permission denied" wait=false count=12466=== CONT TestQueueFetchBatchLimit2467=== CONT TestQueueRemove2468=== CONT TestServerClientIntegration2469=== CONT TestQueueDeduplication2470=== CONT TestQueueEnqueueAndFetch2471=== CONT TestQueueRemoveLargeClosure2472=== CONT TestFailedPathPrunedByLaterClosure2473=== CONT TestDrainIsolatesPoisonPath2474=== CONT TestServerWait2475--- PASS: TestServerQueueError (0.00s)2476--- PASS: TestServerClientIntegration (0.00s)2477--- PASS: TestServerWait (0.00s)24782026/09/07 19:37:27 INFO Uploading batch count=424792026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=424802026/09/07 19:37:27 INFO Uploading batch count=224812026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1614502945/002/bbb24822026/09/07 19:37:27 INFO Upload queue status pending=224832026/09/07 19:37:27 INFO Upload queue status pending=324842026/09/07 19:37:27 INFO Uploading batch count=224852026/09/07 19:37:27 INFO Uploading batch count=124862026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=12487--- PASS: TestQueueFetchBatchLimit (0.01s)24882026/09/07 19:37:27 INFO Upload queue status pending=224892026/09/07 19:37:27 INFO Uploading batch count=124902026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=124912026/09/07 19:37:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4261707025/002/nonexistent2492--- PASS: TestQueueRetryMovesToBack (0.01s)24932026/09/07 19:37:27 INFO Upload queue status pending=224942026/09/07 19:37:27 INFO Uploading batch count=124952026/09/07 19:37:27 INFO Uploading batch count=12496--- PASS: TestQueueEnqueueAndFetch (0.01s)24972026/09/07 19:37:27 INFO Uploading batch count=124982026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=12499--- PASS: TestQueueRemove (0.02s)25002026/09/07 19:37:27 INFO Uploading batch count=225012026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=225022026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2339974537/002/a25032026/09/07 19:37:27 INFO Uploading batch count=125042026/09/07 19:37:27 INFO Uploading batch count=125052026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=12506--- PASS: TestQueueDeduplication (0.02s)25072026/09/07 19:37:27 INFO Uploading batch count=125082026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2339974537/002/b25092026/09/07 19:37:27 INFO Uploading batch count=12510--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25112026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=125122026/09/07 19:37:27 INFO Uploading batch count=225132026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=225142026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2339974537/002/c25152026/09/07 19:37:27 ERROR Drain finished with paths left in queue remaining=125162026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2339974537/002/d25172026/09/07 19:37:27 INFO Uploading batch count=225182026/09/07 19:37:27 ERROR Upload failed error="upload failed" count=225192026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2339974537/002/e2520--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25212026/09/07 19:37:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2339974537/002/f25222026/09/07 19:37:27 ERROR Drain finished with paths left in queue remaining=102523--- PASS: TestDrainIsolatesPoisonPath (0.02s)2524--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2525--- PASS: TestWorkerSkipsGCdPaths (0.03s)2526--- PASS: TestWorkerUploadsAndRemoves (0.03s)2527--- PASS: TestWorkerPrunesClosureDeps (0.04s)25282026/09/07 19:37:27 ERROR Upload failed error="context deadline exceeded" count=225292026/09/07 19:37:27 ERROR Drain finished with paths left in queue remaining=42530--- PASS: TestDrainTimeout (0.21s)2531--- PASS: TestQueueRemoveLargeClosure (0.26s)2532--- PASS: TestQueueConcurrentWriters (0.29s)25332026/09/07 19:37:28 INFO Uploading batch count=125342026/09/07 19:37:28 INFO Uploading batch count=125352026/09/07 19:37:28 INFO Uploading batch count=125362026/09/07 19:37:28 ERROR Upload failed error="upload failed" count=125372026/09/07 19:37:28 INFO Uploading batch count=125382026/09/07 19:37:28 ERROR Upload failed error="upload failed" count=125392026/09/07 19:37:28 INFO Uploading batch count=125402026/09/07 19:37:28 ERROR Upload failed error="upload failed" count=125412026/09/07 19:37:28 INFO Uploading batch count=125422026/09/07 19:37:28 ERROR Upload failed error="upload failed" count=125432026/09/07 19:37:28 ERROR Drain finished with paths left in queue remaining=12544--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2545PASS