Uploaded image for project: 'Sakai'
  1. Sakai
  2. SAK-13457

NPE when merging shared journal segment to local index

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: CLOSED
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 2.5.0
    • Fix Version/s: 2.5.2, 2.6.0
    • Component/s: Search
    • Labels:
      None

      Description

      A new app server comes up with an empty local index, and gives this error when it tries to merge in shared segments:

      WARN: Failed to get read lock on index (2008-04-29 18:17:32,594 http-8443-Processor22_org.sakaiproject.search.journal.impl.JournaledFSIndexStorage)
      INFO: Long time opening 0:10006 ms (2008-04-29 18:17:32,595 http-8443-Processor22_org.sakaiproject.search.journal.impl.JournaledFSIndexStorage)
      INFO: Read Lock aquire 10005 ms (2008-04-29 18:17:32,595 http-8443-Processor22_org.sakaiproject.search.journal.impl.JournaledFSIndexStorage)
      INFO: Index Load aquire 0 ms (2008-04-29 18:17:32,595 http-8443-Processor22_org.sakaiproject.search.journal.impl.JournaledFSIndexStorage)
      INFO: Read Lock Release 0 ms (2008-04-29 18:17:32,595 http-8443-Processor22_org.sakaiproject.search.journal.impl.JournaledFSIndexStorage)
      WARN: Failed to compete merge of 16501 (2008-04-29 18:17:45,628 Timer-3_org.sakaiproject.search.journal.impl.MergeUpdateOperation)
      org.sakaiproject.search.transaction.api.IndexTransactionException: Failed to commit
      at org.sakaiproject.search.transaction.impl.IndexTransactionImpl.commit(IndexTransactionImpl.java:194)
      at org.sakaiproject.search.journal.impl.MergeUpdateOperation.runOnce(MergeUpdateOperation.java:95)
      at org.sakaiproject.search.journal.impl.IndexManagementTimerTask.run(IndexManagementTimerTask.java:135)
      at java.util.TimerThread.mainLoop(Timer.java:512)
      at java.util.TimerThread.run(Timer.java:462)
      Caused by: java.lang.NullPointerException
      at org.sakaiproject.search.journal.impl.RefCountIndexSearcher.forceClose(RefCountIndexSearcher.java:214)
      at org.sakaiproject.search.journal.impl.RefCountIndexSearcher.unbind(RefCountIndexSearcher.java:130)
      at org.sakaiproject.search.journal.impl.RefCountIndexSearcher.close(RefCountIndexSearcher.java:91)
      at org.sakaiproject.search.journal.impl.JournaledFSIndexStorage.loadIndexSearcherInternal(JournaledFSIndexStorage.java:527)
      at org.sakaiproject.search.journal.impl.JournaledFSIndexStorage.loadIndexReader(JournaledFSIndexStorage.java:1373)
      at org.sakaiproject.search.journal.impl.JournaledFSIndexStorageUpdateTransactionListener.commit(JournaledFSIndexStorageUpdateTransactionListener.java:231)
      at org.sakaiproject.search.transaction.impl.IndexTransactionImpl.fireCommit(IndexTransactionImpl.java:323)
      at org.sakaiproject.search.transaction.impl.IndexTransactionImpl.commit(IndexTransactionImpl.java:187)
      ... 4 more
      INFO: Local Merge Operation
      Merged Journal 16502 from the redolog in 210 ms
      Merged Journal 16503 from the redolog in 94 ms
      Merged Journal 16504 from the redolog in 51 ms
      Merged Journal 16505 from the redolog in 50 ms
      Merged Journal 16506 from the redolog in 53 ms
      Merged Journal 16507 from the redolog in 51 ms
      Merged Journal 16508 from the redolog in 58 ms
      Merged Journal 16509 from the redolog in 77 ms
      Merged Journal 16510 from the redolog in 57 ms
      Merged Journal 16511 from the redolog in 62 ms
      Merged Journal 16512 from the redolog in 69 ms
      Merged Journal 16513 from the redolog in 65 ms
      Merged Journal 16514 from the redolog in 64 ms
      Merged Journal 16515 from the redolog in 65 ms
      Merged Journal 16516 from the redolog in 73 ms
      Merged Journal 16517 from the redolog in 66 ms
      Merged Journal 16518 from the redolog in 64 ms
      Merged Journal 16519 from the redolog in 1405 ms
      Merged Journal 16520 from the redolog in 69 ms
      Merged Journal 16521 from the redolog in 64 ms
      Merged Journal 16522 from the redolog in 66 ms
      Merged Journal 16523 from the redolog in 65 ms
      Merged Journal 16524 from the redolog in 76 ms
      Merged Journal 16525 from the redolog in 63 ms
      Merged Journal 16526 from the redolog in 63 ms
      Merged Journal 16527 from the redolog in 62 ms
      Merged Journal 16528 from the redolog in 66 ms
      Merged Journal 16529 from the redolog in 77 ms
      Merged Journal 16530 from the redolog in 75 ms
      Merged Journal 16531 from the redolog in 82 ms
      Merged Journal 16532 from the redolog in 75 ms
      Merged Journal 16533 from the redolog in 85 ms
      Merged Journal 16534 from the redolog in 78 ms
      Merged Journal 16535 from the redolog in 68 ms
      Merged Journal 16536 from the redolog in 77 ms
      Merged Journal 16537 from the redolog in 71 ms
      Merged Journal 16538 from the redolog in 72 ms
      Merged Journal 16539 from the redolog in 77 ms
      Merged Journal 16540 from the redolog in 74 ms
      Merged Journal 16541 from the redolog in 81 ms
      Merged Journal 16542 from the redolog in 80 ms
      Merged Journal 16543 from the redolog in 88 ms
      Merged Journal 16544 from the redolog in 79 ms
      Merged Journal 16545 from the redolog in 80 ms
      Merged Journal 16546 from the redolog in 89 ms
      Merged Journal 16547 from the redolog in 81 ms
      (2008-04-29 18:17:50,348 Timer-3_org.sakaiproject.search.journal.impl.MergeUpdateOperation)
      INFO: Local Merge Operation
      (2008-04-29 18:18:14,174 Timer-3_org.sakaiproject.search.journal.impl.MergeUpdateOperation)

      srvslscle002:~ # ls -l /data/sakai/search/searchjournal/ | more
      total 1267140
      rw-rr- 1 tomcat users 1294704286 2008-04-29 17:22 16501-0.zip
      rw-rr- 1 tomcat users 131035 2008-04-29 16:52 16501.zip
      rw-rr- 1 tomcat users 20176 2008-04-29 16:58 16502.zip
      rw-rr- 1 tomcat users 28302 2008-04-29 17:01 16503.zip
      rw-rr- 1 tomcat users 9873 2008-04-29 17:02 16504.zip
      rw-rr- 1 tomcat users 36871 2008-04-29 17:03 16505.zip
      rw-rr- 1 tomcat users 48335 2008-04-29 17:05 16506.zip
      rw-rr- 1 tomcat users 6864 2008-04-29 17:06 16507.zip
      rw-rr- 1 tomcat users 11612 2008-04-29 17:07 16508.zip
      rw-rr- 1 tomcat users 447625 2008-04-29 17:09 16509.zip
      rw-rr- 1 tomcat users 27429 2008-04-29 17:10 16510.zip
      rw-rr- 1 tomcat users 7785 2008-04-29 17:11 16511.zip
      rw-rr- 1 tomcat users 66743 2008-04-29 17:12 16512.zip
      rw-rr- 1 tomcat users 7734 2008-04-29 17:14 16513.zip
      rw-rr- 1 tomcat users 7878 2008-04-29 17:15 16514.zip
      rw-rr- 1 tomcat users 6178 2008-04-29 17:16 16515.zip
      rw-rr- 1 tomcat users 4642 2008-04-29 17:17 16516.zip
      rw-rr- 1 tomcat users 24015 2008-04-29 17:19 16517.zip
      rw-rr- 1 tomcat users 28141 2008-04-29 17:20 16518.zip
      rw-rr- 1 tomcat users 7300 2008-04-29 17:21 16519.zip
      rw-rr- 1 tomcat users 48225 2008-04-29 17:24 16520.zip
      rw-rr- 1 tomcat users 15298 2008-04-29 17:26 16521.zip
      rw-rr- 1 tomcat users 7038 2008-04-29 17:28 16522.zip
      rw-rr- 1 tomcat users 5651 2008-04-29 17:29 16523.zip
      rw-rr- 1 tomcat users 15995 2008-04-29 17:31 16524.zip
      rw-rr- 1 tomcat users 5104 2008-04-29 17:32 16525.zip
      rw-rr- 1 tomcat users 3590 2008-04-29 17:34 16526.zip
      rw-rr- 1 tomcat users 7680 2008-04-29 17:35 16527.zip
      rw-rr- 1 tomcat users 6002 2008-04-29 17:37 16528.zip
      rw-rr- 1 tomcat users 14561 2008-04-29 17:38 16529.zip
      rw-rr- 1 tomcat users 7455 2008-04-29 17:39 16530.zip
      rw-rr- 1 tomcat users 8132 2008-04-29 17:40 16531.zip
      rw-rr- 1 tomcat users 6663 2008-04-29 17:42 16532.zip
      rw-rr- 1 tomcat users 8769 2008-04-29 17:43 16533.zip
      rw-rr- 1 tomcat users 201629 2008-04-29 17:44 16534.zip
      rw-rr- 1 tomcat users 5056 2008-04-29 17:46 16535.zip
      rw-rr- 1 tomcat users 10285 2008-04-29 17:48 16536.zip
      rw-rr- 1 tomcat users 5155 2008-04-29 17:49 16537.zip
      rw-rr- 1 tomcat users 5055 2008-04-29 17:51 16538.zip
      rw-rr- 1 tomcat users 2877 2008-04-29 17:52 16539.zip
      rw-rr- 1 tomcat users 3936 2008-04-29 17:53 16540.zip
      rw-rr- 1 tomcat users 5027 2008-04-29 17:54 16541.zip
      rw-rr- 1 tomcat users 12659 2008-04-29 17:56 16542.zip
      rw-rr- 1 tomcat users 76659 2008-04-29 18:06 16543.zip
      rw-rr- 1 tomcat users 2627 2008-04-29 18:10 16544.zip
      rw-rr- 1 tomcat users 3004 2008-04-29 18:12 16545.zip
      rw-rr- 1 tomcat users 5700 2008-04-29 18:15 16546.zip
      rw-rr- 1 tomcat users 3087 2008-04-29 18:17 16547.zip
      rw-rr- 1 tomcat users 2967 2008-04-29 18:19 16548.zip
      rw-rr- 1 tomcat users 2629 2008-04-29 18:20 16549.zip
      rw-rr- 1 tomcat users 38494 2008-04-29 18:20 16550.zip

      mysql> select * from search_journal;
      ------------------------------------------------+

      txid txts indexwriter status

      ------------------------------------------------+

      16501 1209482622727 vula2a:1209228476933 commited
      16502 1209481106026 vula3a commited
      16503 1209481286854 vula3a commited
      16504 1209481356508 vula3a commited
      16505 1209481426666 vula3a commited
      16506 1209481506883 vula3a commited
      16507 1209481586615 vula3a commited
      16508 1209481656717 vula3a commited
      16509 1209481757758 vula3a commited
      16510 1209481817984 vula3a commited
      16511 1209481888029 vula3a commited
      16512 1209481961965 vula3a commited
      16513 1209482048029 vula3a commited
      16514 1209482118157 vula3a commited
      16515 1209482188094 vula3a commited
      16516 1209482258181 vula3a commited
      16517 1209482348308 vula3a commited
      16518 1209482418389 vula3a commited
      16519 1209482488417 vula3a commited
      16520 1209482673289 vula2a commited
      16521 1209482813212 vula2a commited
      16522 1209482883134 vula2a commited
      16523 1209482963139 vula2a commited
      16524 1209483103457 vula2a commited
      16525 1209483173254 vula2a commited
      16526 1209483243257 vula2a commited
      16527 1209483353406 vula2a commited
      16528 1209483423385 vula2a commited
      16529 1209483493541 vula2a commited
      16530 1209483564423 vula2a commited
      16531 1209483653557 vula2a commited
      16532 1209483723561 vula2a commited
      16533 1209483793745 vula2a commited
      16534 1209483883053 vula2a commited
      16535 1209483973242 vula2a commited
      16536 1209484113412 vula2a commited
      16537 1209484193355 vula2a commited
      16538 1209484263386 vula2a commited
      16539 1209484333393 vula2a commited
      16540 1209484403449 vula2a commited
      16541 1209484493533 vula2a commited
      16542 1209484563679 vula2a commited
      16543 1209485202004 vula2a commited
      16544 1209485450694 vula2a commited
      16545 1209485520716 vula2a commited
      16546 1209485741612 vula3a commited
      16547 1209485841616 vula3a commited
      16548 1209485970545 vula2a commited
      16549 1209486011695 vula3a commited
      16550 1209486051115 vula2a commited

      ------------------------------------------------+
      50 rows in set (0.00 sec)

        Gliffy Diagrams

          Zeplin

            Attachments

              Activity

                People

                • Assignee:
                  smarquard Stephen Marquard
                  Reporter:
                  smarquard Stephen Marquard
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  0 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved:

                    Git Integration