손상된 인덱스로 인해 복원 불가 (손상된 인덱스 해결 방법 힌트 포함)

제품 지원 자체 호스팅
1

에러로 인해 이 백업이 여러 번 실패했습니다. 예:

ERROR:  could not create unique index "index_incoming_referers_on_path_and_incoming_domain_id"
DETAIL:  Key (path, incoming_domain_id)=(/@dataandme, 41) is duplicated.               
ERROR:  current transaction is aborted, commands ignored until end of transaction block

Rails에서 IncomingReferer.where(path: '/@dataandme').destroy_all 같은 명령을 사용하여 해당 레코드들을 수동으로 모두 삭제했습니다.

그런데 여전히 실패하고 있습니다.

...
[2019-12-30 20:29:16] 'pfaffman' has started the restore!
[2019-12-30 20:29:16] Marking restore as running...
[2019-12-30 20:29:16] Making sure /var/www/discourse/tmp/restores/default/2019-12-30-202916 exists...
[2019-12-30 20:29:16] Downloading archive to tmp directory...
[2019-12-30 20:29:38] No metadata file to extract.
[2019-12-30 20:29:38] Validating metadata...
[2019-12-30 20:29:38]   Current version: 20191129144706
[2019-12-30 20:29:38]   Restored version: 20191129144706
[2019-12-30 20:29:38] Extracting dump file...
[2019-12-30 20:30:07] Creating missing functions in the discourse_functions schema
[2019-12-30 20:30:08] Cannot restore into different schema, restoring in-place
[2019-12-30 20:30:08] Enabling readonly mode...
[2019-12-30 20:30:08] Pausing sidekiq...
[2019-12-30 20:30:08] Waiting for sidekiq to finish running jobs...
[2019-12-30 20:30:08] Restoring dump file... (can be quite long)

 ----- and so on -----
[2019-12-30 20:33:17] ERROR:  current transaction is aborted, commands ignored until end of transaction block
[2019-12-30 20:33:17] ERROR:  current transaction is aborted, commands ignored until end of transaction block
[2019-12-30 20:33:17] EXCEPTION: psql failed
[2019-12-30 20:33:17] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
/var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
/var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
/var/www/discourse/lib/backup_restore.rb:163:in `fork'
/var/www/discourse/lib/backup_restore.rb:163:in `start!'
/var/www/discourse/lib/backup_restore.rb:22:in `restore!'
/var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/base.rb:196:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rendering.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/callbacks.rb:135:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/base.rb:136:in `process'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:39:in `process'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.3/lib/mini_profiler/profiling_methods.rb:104:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal.rb:191:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal.rb:252:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/route_set.rb:51:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/mapper.rb:18:in `block in <class:Constraints>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/mapper.rb:48:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/journey/router.rb:49:in `block in serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/journey/router.rb:32:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/journey/router.rb:32:in `serve'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/routing/route_set.rb:837:in `call'
/var/www/discourse/lib/middleware/omniauth_bypass_middleware.rb:68:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/tempfile_reaper.rb:15:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/conditional_get.rb:38:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/head.rb:12:in `call'
/var/www/discourse/lib/content_security_policy/middleware.rb:12:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:318:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/session/abstract/id.rb:232:in `context'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/session/abstract/id.rb:226:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/cookies.rb:648:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/actionable_exceptions.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/logster-2.4.2/lib/logster/middleware/reporter.rb:43:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/rack/logger.rb:28:in `call'
/var/www/discourse/config/initializers/100-quiet_logger.rb:18:in `call'
/var/www/discourse/config/initializers/100-silence_logger.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/var/www/discourse/lib/middleware/enforce_hostname.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/method_override.rb:22:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/sendfile.rb:111:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_dispatch/middleware/host_authorization.rb:77:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-mini-profiler-1.1.3/lib/mini_profiler/profiler.rb:296:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/message_bus-2.2.3/lib/message_bus/rack/middleware.rb:57:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:181:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/engine.rb:526:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/railtie.rb:190:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/railties-6.0.1/lib/rails/railtie.rb:190:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:68:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:53:in `each'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/rack-2.0.7/lib/rack/urlmap.rb:53:in `call'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:605:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:700:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:548:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/lib/unicorn/http_server.rb:144:in `start'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/unicorn-5.5.1/bin/unicorn:128:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.6.0/bin/unicorn:23:in `<main>'
[2019-12-30 20:33:17] Trying to rollback...
[2019-12-30 20:33:17] Rolling back...
[2019-12-30 20:33:17] Cleaning stuff up...
[2019-12-30 20:33:17] Dropping function from the discourse_functions schema
[2019-12-30 20:33:17] Removing tmp '/var/www/discourse/tmp/restores/default/2019-12-30-202916' directory...
[2019-12-30 20:33:17] Unpausing sidekiq...
[2019-12-30 20:33:17] Disabling readonly mode...
[2019-12-30 20:33:17] Marking restore as finished...
[2019-12-30 20:33:17] Notifying 'pfaffman' of the end of the restore...
[2019-12-30 20:33:34] Finished!

이제 어떻게 수정해야 할지 알 수 없는 부분이 보입니다.

복원하려는 스테이징 사이트는 업그레이드할 수 있지만, 스테이징에서 정상 작동하는지 먼저 확인하기 전에 프로덕션 사이트를 업그레이드하는 것은 피하고 싶습니다…

2

psql이 그 이전에 다른 오류를 기록하지 않은 것을 확인하셨나요? 이는 일반적으로 이전 SQL 명령이 실패했을 때 발생합니다.

또한, 원래 데이터베이스의 incoming_referers 테이블에 중복된 레코드가 있는 이유는 무엇인가요? 해당 테이블의 고유 인덱스는 2014년부터 존재해 왔습니다. 복원하려는 데이터베이스에 이보다 훨씬 많은 문제가 있는 것은 아닌지 확인해 보시는 것이 좋습니다.

3

Gerhard님, 감사합니다! 도움을 주셔서 정말 감사드립니다. 이 문제는 점점 더 기묘해지고 있습니다.

incoming_referers에 문제가 있었다는 것도 저한테는 이해가 안 됩니다. 10월에도 프로덕션에서 이 스테이징 사이트로 복원을 한 적이 있습니다.

데이터베이스나 인덱스에 뭔가 문제가 있는 것 같습니다. 플러그인 때문이라고 의심했지만, 에러가 서로 다른 인덱스 여러 곳에서 발생하고 있어 단일 플러그인이 원인이었을 가능성은 낮아 보입니다. 손상된 인덱스 문제를 찾기 위해 플러그인에서 grep을 수행해 보았지만 아무것도 나오지 않았습니다.

최근 한 번의 복원에서는 다음과 같은 결과가 나왔습니다:

[2020-01-03 16:25:30] ERROR:  could not create unique index "index_plugin_store_rows_on_plugin_name_and_key"

다음과 같이 실행해 보았습니다:

[10] pry(main)> PluginStoreRow.where(plugin_name: 'discourse-data-explorer',key: 'q:-8').destroy_all

그리고 다시 시도했습니다:

[2020-01-03 16:49:16] ERROR:  could not create unique index "index_tags_on_lower_name"
[2020-01-03 16:49:16] DETAIL:  Key (lower(name::text))=(addins) is duplicated.

최근 복원의 전체 로그 상단 부분은 다음과 같습니다:

[2020-01-03 16:41:34] 'pfaffman' has started the restore!
[2020-01-03 16:41:34] Marking restore as running...
[2020-01-03 16:41:34] Making sure /var/www/discourse/tmp/restores/default/2020-01-03-164133 exists...
[2020-01-03 16:41:34] Downloading archive to tmp directory...
[2020-01-03 16:45:20] No metadata file to extract.
[2020-01-03 16:45:20] Validating metadata...
[2020-01-03 16:45:20]   Current version: 20191220134101
[2020-01-03 16:45:20]   Restored version: 20191129144706
[2020-01-03 16:45:20] Extracting dump file...
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:15] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] CREATE INDEX
[2020-01-03 16:49:16] ERROR:  could not create unique index "index_tags_on_lower_name"
[2020-01-03 16:49:16] DETAIL:  Key (lower(name::text))=(addins) is duplicated.
[2020-01-03 16:49:16] ERROR:  current transaction is aborted, commands ignored until end of transaction block
[2020-01-03 16:49:16] ERROR:  current transaction is aborted, commands ignored until end of transaction block
[2020-01-03 16:49:16] ERROR:  current transaction is aborted, commands ignored until end of transaction block
4

복원이 정상적으로 작동하고 모든 고유 인덱스가 생성될 때까지 데이터를 수동으로 정리해야 할 것 같습니다.

그 aside로, 최근 기본 이미지 중 하나에 버그가 있는 PostgreSQL 버전이 배포된 건 아닌지 궁금합니다. 지난 1~2개월 동안 손상된 인덱스 관련 문제가 꽤 많이 보고되었거든요. 이상한 우연인 것 같습니다. :thinking:

6

"제이가 또 바보 같은 짓을 했다"는 설명 말고 다른 설명을 듣고 싶습니다. :wink:

참고로, 이 문제가 시작되기 직전에 이 사이트의 데이터 컨테이너를 업그레이드한 것으로 꽤 확신하고 있습니다.

8

중복 레코드의 created_at 날짜를 확인하여 당시 어떤 버전의 Postgres가 사용되었는지 파악해 볼 수 있습니다. @falco는 PG 10.0과 10.1에서 인덱스 손상 문제가 있었다고 언급했지만, 그것은 꽤 오래된 일입니다(10.2는 2018-02-08에 출시되었습니다). 그리고 우리는 2018년 4월에야 PG 10의 공급을 시작했으므로(즉, 10.2 출시 이후) 이는 PG의 새로운 버그이거나 단순히 운이 나빴던 것일 수 있습니다. :man_shrugging:

9

음. 프로덕션에는 10.10, 스테이징에는 10.11이 설치되어 있네요.

또한, 로그에 중복으로 인해 실패했다고 표시된 레코드 중에는 실제로는 레코드가 하나만 있는 경우가 몇 개 있었습니다. 혹시 레코드는 삭제되었지만 인덱스에서는 삭제되지 않은 건가요? 그럴 수 있을까요?

10

자, 하지만 인덱스는 업데이트될 때마다 재생성되지 않습니다.

네, 디스크에서 서로 다른 객체이기 때문입니다.

11

음, 여기 단서가 있습니다:

discourse=> reindex table tags;
ERROR:  could not create unique index "index_tags_on_lower_name"
DETAIL:  Key (lower(name::text))=(addins) is duplicated.

discourse=> select * from tags where name='addins';
 id  |  name  | topic_count |         created_at         |         updated_at         | pm_topic_count 
-----+--------+-------------+----------------------------+----------------------------+----------------
 143 | addins |          16 | 2017-11-13 20:08:51.345607 | 2017-11-13 20:08:51.345607 |              0
(1 row)

discourse=> select * from tags where name like '%dins';
 id  |  name  | topic_count |         created_at         |         updated_at         | pm_topic_count 
-----+--------+-------------+----------------------------+----------------------------+----------------
 143 | addins |          16 | 2017-11-13 20:08:51.345607 | 2017-11-13 20:08:51.345607 |              0
 721 | addins |           3 | 2019-11-19 10:01:32.406178 | 2019-11-19 10:01:32.406178 |              0

이 둘의 차이를 알 수 없는데, 첫 번째 select 문에서는 둘 중 하나만 찾았나요?

12

EXPLAIN ANALYZE select * from tags where name='addins';를 실행하면 그 이유를 알 수 있습니다.

인덱스 전용 스캔(index only scan)이었을 수도 있지만(너무 많은 컬럼을 선택하고 있으므로 가능성은 낮습니다), 인덱스를 사용하여 어떤 행을 선택할지 파악하는 비트맵 힙 스캔(bitmap heap scan)이었을 가능성이 높습니다. 인덱스가 손상되어 있기 때문에…

13

최근 제가 손상된 인덱스에서 겪었던 문제와 정확히 같은 상황입니다. 해당 계정들을 검사해 보니 대부분 같은 계정(같은 이메일 주소)인 경우가 많았고, 하나를 이름 변경한 뒤 병합했습니다. 대부분 수동으로 작업해야 해서 꽤 많은 시간이 걸렸지만, 이제 반짝반짝한 새 인덱스를 갖게 되었습니다 :slight_smile:

수정: 아, 제 문제는 users 테이블에 있었습니다. 다만 동일한 중복 키 문제였죠.

14

이번에도 'shiny-server’는 하나만 일치했지만 '%hiney-server’는 둘 다 일치하는 두 개의 항목이 있었습니다. 이게 제가 이해하는 데 어떻게 도움이 되는지 모르겠지만, 제가 사용하는 select가 하나의 결과만 반환되기를 기대하고 인덱스에서 그것을 가져오며 나머지는 무시한다는 말씀인 것 같습니다. 하지만 %를 사용하면 필드를 검색하게 되죠.

discourse=> EXPLAIN ANALYZE select * from tags where name='shiny-server'; 
                                                        QUERY PLAN                                                        
--------------------------------------------------------------------------------------------------------------------------
 Index Scan using index_tags_on_name on tags  (cost=0.28..8.29 rows=1 width=36) (actual time=0.038..0.040 rows=1 loops=1)
   Index Cond: ((name)::text = 'shiny-server'::text)
 Planning time: 0.129 ms
 Execution time: 0.070 ms
(4 rows)

이걸 스스로 알아내지 못하는 사람들이 이걸 유용하게 볼 거라고는 솔직히 의문이 듭니다. 하지만 … 이름이 같은 두 개의 tag_id를 찾아서 다음과 같은 작업을 수행해 보았습니다.

 TopicTag.where(tag_id: 717).update_all(tag_id: 611)
 Tag.ensure_consistency!
 Tag.find(717) # 어떤 주제에도 포함되지 않는지 확인
 Tag.find(717).destroy

그리고 psql에서 reindex table tags;를 실행했습니다.

이제 @bartv님이 설명하신 것처럼 users에 대해서도 유사한 작업을 해야 할 것 같습니다. 다만 제 경우를 보면 David라는 유저와 david라는 유저, 그리고 [Mm]ark도 있습니다.

그것들은 다음과 같이 수정했습니다.

marks=User.where("username similar to  '[Mm]+ark'").pluck(:id,:username,:created_at)

그 다음 /admin/users에서 새로운 mark를 찾아서 거기서 유저 이름을 변경했습니다. 그리고 psql에서 reindex table users;를 시도해 보았습니다. (sudo su - discourse를 실행한 후 psql을 실행합니다).

15

이렇게 생각해 보세요. 전화부에서 Pfaffman을 찾아야 한다면, P로 간 다음 Pe와 Pg 사이의 항목을 찾고, 그 다음 Pfa와 Pfb 사이를 찾는 식으로 찾습니다. 항목이 알파벳 순서로 정렬되어 있다는 사실을 이용해 빠르게 항목을 찾아내는 것이죠. 이제 마음의 실험을 해 봅시다. 전화부 편집자 중 한 명이 알파벳을 제대로 외우지 못해 일부 Pfaffman 항목을 잘못된 위치에 삽입했다고 가정해 보세요(손상된 인덱스). 그러면 그들을 찾지 못할 것입니다.

이제 성이 faffman으로 끝나는 모든 사람을 찾아야 한다고 해 봅시다. 이를 위한 빠른 방법은 없으며, 전화부 전체를 훑어봐야 합니다. 상당한 일이죠! 하지만… 이 방식으로는 잘못 삽입된 Pfaffman들도 찾을 수 있습니다!