Java Code Examples for org.apache.solr.common.SolrException#log()

/**
 * Pass "null" for the client to query to the local server.
 * Fetches response in xml format and matches with the given set of xpaths
 */
public static void assertQ(SolrClient client, SolrParams args, String... tests) throws Exception {
  String resp;
  resp = getQueryResponse(client, "xml", args);
  try {
    String results = TestHarness.validateXPath(resp, tests);
    if (null != results) {
      String msg = "REQUEST FAILED: xpath=" + results
          + "\n\txml response was: " + resp
          + "\n\tparams were:" + args.toQueryString();

      log.error(msg);
      throw new RuntimeException(msg);
    }
  } catch (XPathExpressionException e1) {
    throw new RuntimeException("XPath is invalid", e1);
  } catch (Exception e2) {
    SolrException.log(log,"REQUEST FAILED for params: " + args.toQueryString(), e2);
    throw new RuntimeException("Exception during query", e2);
  }
}
 

/** currently for testing only */
public void deleteAll() {
  synchronized (this) {

    try {
      RefCounted<SolrIndexSearcher> holder = uhandler.core.openNewSearcher(true, true);
      holder.decref();
    } catch (Exception e) {
      SolrException.log(log, "Error opening realtime searcher for deleteByQuery", e);
    }

    if (map != null) map.clear();
    if (prevMap != null) prevMap.clear();
    if (prevMap2 != null) prevMap2.clear();

    oldDeletes.clear();
    deleteByQueries.clear();
  }
}
 

private RefCounted<SolrIndexSearcher> newHolder(SolrIndexSearcher newSearcher, final List<RefCounted<SolrIndexSearcher>> searcherList) {
  RefCounted<SolrIndexSearcher> holder = new RefCounted<SolrIndexSearcher>(newSearcher) {
    @Override
    public void close() {
      try {
        synchronized (searcherLock) {
          // it's possible for someone to get a reference via the _searchers queue
          // and increment the refcount while RefCounted.close() is being called.
          // we check the refcount again to see if this has happened and abort the close.
          // This relies on the RefCounted class allowing close() to be called every
          // time the counter hits zero.
          if (refcount.get() > 0) return;
          searcherList.remove(this);
        }
        resource.close();
      } catch (Exception e) {
        // do not allow decref() operations to fail since they are typically called in finally blocks
        // and throwing another exception would be very unexpected.
        SolrException.log(log, "Error closing searcher:" + this, e);
      }
    }
  };
  holder.incref();  // set ref count to 1 to account for this._searcher
  return holder;
}
 

/** Opens a new realtime searcher and clears the id caches.
 * This may also be called when we updates are being buffered (from PeerSync/IndexFingerprint)
 */
public void openRealtimeSearcher() {
  synchronized (this) {
    // We must cause a new IndexReader to be opened before anything looks at these caches again
    // so that a cache miss will read fresh data.
    try {
      RefCounted<SolrIndexSearcher> holder = uhandler.core.openNewSearcher(true, true);
      holder.decref();
    } catch (Exception e) {
      SolrException.log(log, "Error opening realtime searcher", e);
      return;
    }

    if (map != null) map.clear();
    if (prevMap != null) prevMap.clear();
    if (prevMap2 != null) prevMap2.clear();
  }
}
 

/** This is the worker part for the ScheduledFuture **/
@Override
public void run() {
  synchronized (this) {
    // log.info("###start commit. pending=null");
    pending = null;  // allow a new commit to be scheduled
  }

  MDCLoggingContext.setCore(core);
  try (SolrQueryRequest req = new LocalSolrQueryRequest(core, new ModifiableSolrParams())) {
    CommitUpdateCommand command = new CommitUpdateCommand(req, false);
    command.openSearcher = openSearcher;
    command.waitSearcher = WAIT_SEARCHER;
    command.softCommit = softCommit;
    if (core.getCoreDescriptor().getCloudDescriptor() != null
        && core.getCoreDescriptor().getCloudDescriptor().isLeader()
        && !softCommit) {
      command.version = core.getUpdateHandler().getUpdateLog().getVersionInfo().getNewClock();
    }
    // no need for command.maxOptimizeSegments = 1; since it is not optimizing

    // we increment this *before* calling commit because it was causing a race
    // in the tests (the new searcher was registered and the test proceeded
    // to check the commit count before we had incremented it.)
    autoCommitCount.incrementAndGet();

    core.getUpdateHandler().commit(command);
  } catch (Exception e) {
    SolrException.log(log, "auto commit error...", e);
  } finally {
    MDCLoggingContext.clear();
  }
  // log.info("###done committing");
}
 

/**
 * Calls <code>mutate</code> on any fields identified by the selector 
 * before forwarding the command down the chain.  Any SolrExceptions 
 * thrown by <code>mutate</code> will be logged with the Field name, 
 * wrapped and re-thrown.
 */
@Override
public void processAdd(AddUpdateCommand cmd) throws IOException {
  final SolrInputDocument doc = cmd.getSolrInputDocument();

  // make a copy we can iterate over while mutating the doc
  final Collection<String> fieldNames 
    = new ArrayList<>(doc.getFieldNames());

  for (final String fname : fieldNames) {

    if (! selector.shouldMutate(fname)) continue;
    
    final SolrInputField src = doc.get(fname);

    SolrInputField dest = null;
    try { 
      dest = mutate(src);
    } catch (SolrException e) {
      String msg = "Unable to mutate field '"+fname+"': "+e.getMessage();
      SolrException.log(log, msg, e);
      throw new SolrException(BAD_REQUEST, msg, e);
    }
    if (null == dest) {
      doc.remove(fname);
    } else {
      // semantics of what happens if dest has diff name are hard
      // we could treat it as a copy, or a rename
      // for now, don't allow it.
      if (! fname.equals(dest.getName()) ) {
        throw new SolrException(SERVER_ERROR,
                                "mutate returned field with different name: " 
                                + fname + " => " + dest.getName());
      }
      doc.put(dest.getName(), dest);
    }
  }
  super.processAdd(cmd);
}
 

@Override
@SuppressWarnings("unchecked")
public OverseerSolrResponse processMessage(ZkNodeProps message, String operation) {
  MDCLoggingContext.setCollection(message.getStr(COLLECTION));
  MDCLoggingContext.setShard(message.getStr(SHARD_ID_PROP));
  MDCLoggingContext.setReplica(message.getStr(REPLICA_PROP));
  log.debug("OverseerCollectionMessageHandler.processMessage : {} , {}", operation, message);

  @SuppressWarnings({"rawtypes"})
  NamedList results = new NamedList();
  try {
    CollectionAction action = getCollectionAction(operation);
    Cmd command = commandMap.get(action);
    if (command != null) {
      command.call(cloudManager.getClusterStateProvider().getClusterState(), message, results);
    } else {
      throw new SolrException(ErrorCode.BAD_REQUEST, "Unknown operation:"
          + operation);
    }
  } catch (Exception e) {
    String collName = message.getStr("collection");
    if (collName == null) collName = message.getStr(NAME);

    if (collName == null) {
      SolrException.log(log, "Operation " + operation + " failed", e);
    } else  {
      SolrException.log(log, "Collection: " + collName + " operation: " + operation
          + " failed", e);
    }

    results.add("Operation " + operation + " caused exception:", e);
    SimpleOrderedMap<Object> nl = new SimpleOrderedMap<>();
    nl.add("msg", e.getMessage());
    nl.add("rspCode", e instanceof SolrException ? ((SolrException)e).code() : -1);
    results.add("exception", nl);
  }
  return new OverseerSolrResponse(results);
}
 

private void doRequest(final Req req) {
  try {
    SolrClient solrClient = clients.getSolrClient(req);
    solrClient.request(req.uReq);
  } catch (Exception e) {
    SolrException.log(log, e);
    Error error = new Error();
    error.e = e;
    error.req = req;
    if (e instanceof SolrException) {
      error.statusCode = ((SolrException) e).code();
    }
    errors.add(error);
  }
}
 

private void requestRecovery(final ZkNodeProps leaderProps, final String baseUrl, final String coreName) throws SolrServerException, IOException {
  Thread thread = new Thread() {
    {
      setDaemon(true);
    }
    @Override
    public void run() {
      
      if (isClosed) {
        log.info("We have been closed, won't request recovery");
        return;
      }
      RequestRecovery recoverRequestCmd = new RequestRecovery();
      recoverRequestCmd.setAction(CoreAdminAction.REQUESTRECOVERY);
      recoverRequestCmd.setCoreName(coreName);
      
      try (HttpSolrClient client = new HttpSolrClient.Builder(baseUrl)
          .withHttpClient(SyncStrategy.this.client)
          .withConnectionTimeout(30000)
          .withSocketTimeout(120000)
          .build()) {
        client.request(recoverRequestCmd);
      } catch (Throwable t) {
        SolrException.log(log, ZkCoreNodeProps.getCoreUrl(leaderProps) + ": Could not tell a replica to recover", t);
        if (t instanceof Error) {
          throw (Error) t;
        }
      }
    }
  };
  updateExecutor.execute(thread);
}
 

public void close(boolean committed, boolean deleteOnClose) {
  recoveryExecutor.shutdown(); // no new tasks

  synchronized (this) {

    // Don't delete the old tlogs, we want to be able to replay from them and retrieve old versions

    doClose(prevTlog, committed);
    doClose(tlog, committed);

    for (TransactionLog log : logs) {
      if (log == prevTlog || log == tlog) continue;
      log.deleteOnClose = false;
      log.decref();
      log.forceClose();
    }

    if (bufferTlog != null) {
      // should not delete bufferTlog on close, existing bufferTlog is a sign for skip peerSync
      bufferTlog.deleteOnClose = false;
      bufferTlog.decref();
      bufferTlog.forceClose();
    }

  }

  try {
    ExecutorUtil.shutdownAndAwaitTermination(recoveryExecutor);
  } catch (Exception e) {
    SolrException.log(log, e);
  }
}
 

private static void closeHooks(SolrRequestInfo info) {
  if (info.closeHooks != null) {
    for (Closeable hook : info.closeHooks) {
      try {
        hook.close();
      } catch (Exception e) {
        SolrException.log(log, "Exception during close hook", e);
      }
    }
  }
}
 

@Override
public void warm(SolrIndexSearcher searcher, SolrCache<K,V> old) {
  if (regenerator == null) {
    return;
  }
  
  long warmingStartTime = System.nanoTime();
  Map<K, V> hottest = Collections.emptyMap();
  CaffeineCache<K,V> other = (CaffeineCache<K,V>)old;

  // warm entries
  if (isAutowarmingOn()) {
    Eviction<K, V> policy = other.cache.policy().eviction().get();
    int size = autowarm.getWarmCount(other.cache.asMap().size());
    hottest = policy.hottest(size);
  }

  for (Entry<K, V> entry : hottest.entrySet()) {
    try {
      boolean continueRegen = regenerator.regenerateItem(
          searcher, this, old, entry.getKey(), entry.getValue());
      if (!continueRegen) {
        break;
      }
    }
    catch (Exception e) {
      SolrException.log(log, "Error during auto-warming of key:" + entry.getKey(), e);
    }
  }

  inserts.reset();
  priorStats = other.cache.stats().plus(other.priorStats);
  priorInserts = other.inserts.sum() + other.priorInserts;
  warmupTime = TimeUnit.MILLISECONDS.convert(System.nanoTime() - warmingStartTime, TimeUnit.NANOSECONDS);
}
 

/**
 * The main method which downloads file
 */
public void fetchFile() throws Exception {
  bytesDownloaded = 0;
  try {
    fetch();
  } catch(Exception e) {
    if (!aborted) {
      SolrException.log(IndexFetcher.log, "Error fetching file, doing one retry...", e);
      // one retry
      fetch();
    } else {
      throw e;
    }
  }
}
 

/**
 * Logs an error and throws an exception if any of the element(s) at the given elementXpath
 * contains an attribute name that is not among knownAttributes. 
 */
public void complainAboutUnknownAttributes(String elementXpath, String... knownAttributes) {
  SortedMap<String,SortedSet<String>> problems = new TreeMap<>();
  NodeList nodeList = getNodeList(elementXpath, false);
  for (int i = 0 ; i < nodeList.getLength() ; ++i) {
    Element element = (Element)nodeList.item(i);
    Set<String> unknownAttributes = getUnknownAttributes(element, knownAttributes);
    if (null != unknownAttributes) {
      String elementName = element.getNodeName();
      SortedSet<String> allUnknownAttributes = problems.get(elementName);
      if (null == allUnknownAttributes) {
        allUnknownAttributes = new TreeSet<>();
        problems.put(elementName, allUnknownAttributes);
      }
      allUnknownAttributes.addAll(unknownAttributes);
    }
  }
  if (problems.size() > 0) {
    StringBuilder message = new StringBuilder();
    for (Map.Entry<String,SortedSet<String>> entry : problems.entrySet()) {
      if (message.length() > 0) {
        message.append(", ");
      }
      message.append('<');
      message.append(entry.getKey());
      for (String attributeName : entry.getValue()) {
        message.append(' ');
        message.append(attributeName);
        message.append("=\"...\"");
      }
      message.append('>');
    }
    message.insert(0, "Unknown attribute(s) on element(s): ");
    String msg = message.toString();
    SolrException.log(log, msg);
    throw new SolrException(SolrException.ErrorCode.SERVER_ERROR, msg);
  }
}
 

/** Validates a query matches some XPath test expressions and closes the query */
public static void assertQ(String message, SolrQueryRequest req, String... tests) {
  try {
    String m = (null == message) ? "" : message + " "; // TODO log 'm' !!!
    //since the default (standard) response format is now JSON
    //need to explicitly request XML since this class uses XPath
    ModifiableSolrParams xmlWriterTypeParams = new ModifiableSolrParams(req.getParams());
    xmlWriterTypeParams.set(CommonParams.WT,"xml");
    //for tests, let's turn indention off so we don't have to handle extraneous spaces
    xmlWriterTypeParams.set("indent", xmlWriterTypeParams.get("indent", "off"));
    req.setParams(xmlWriterTypeParams);
    String response = h.query(req);

    if (req.getParams().getBool("facet", false)) {
      // add a test to ensure that faceting did not throw an exception
      // internally, where it would be added to facet_counts/exception
      String[] allTests = new String[tests.length+1];
      System.arraycopy(tests,0,allTests,1,tests.length);
      allTests[0] = "*[count(//lst[@name='facet_counts']/*[@name='exception'])=0]";
      tests = allTests;
    }

    String results = BaseTestHarness.validateXPath(response, tests);

    if (null != results) {
      String msg = "REQUEST FAILED: xpath=" + results
          + "\n\txml response was: " + response
          + "\n\trequest was:" + req.getParamString();

      log.error(msg);
      throw new RuntimeException(msg);
    }

  } catch (XPathExpressionException e1) {
    throw new RuntimeException("XPath is invalid", e1);
  } catch (Exception e2) {
    SolrException.log(log,"REQUEST FAILED: " + req.getParamString(), e2);
    throw new RuntimeException("Exception during query", e2);
  }
}
 

public synchronized void connected() {
  for (ConnectedListener listener : connectedListeners) {
    try {
      listener.connected();
    } catch (Exception e) {
      SolrException.log(log, "", e);
    }
  }
}
 

private boolean areAllReplicasParticipating() throws InterruptedException {
  final String shardsElectZkPath = electionPath + LeaderElector.ELECTION_NODE;
  final DocCollection docCollection = zkController.getClusterState().getCollectionOrNull(collection);

  if (docCollection != null && docCollection.getSlice(shardId) != null) {
    final Slice slices = docCollection.getSlice(shardId);
    int found = 0;
    try {
      found = zkClient.getChildren(shardsElectZkPath, null, true).size();
    } catch (KeeperException e) {
      if (e instanceof KeeperException.SessionExpiredException) {
        // if the session has expired, then another election will be launched, so
        // quit here
        throw new SolrException(ErrorCode.SERVER_ERROR,
            "ZK session expired - cancelling election for " + collection + " " + shardId);
      }
      SolrException.log(log, "Error checking for the number of election participants", e);
    }

    if (found >= slices.getReplicasMap().size()) {
      log.debug("All replicas are ready to participate in election.");
      return true;
    }
  } else {
    log.warn("Shard not found: {} for collection {}", shardId, collection);
    return false;
  }
  return false;
}
 

@Override
public void execute(CallInfo it) throws Exception {
  final SolrParams params = it.req.getParams();

  log.info("I have been requested to sync up my shard");

  String cname = params.required().get(CoreAdminParams.CORE);

  ZkController zkController = it.handler.coreContainer.getZkController();
  if (zkController == null) {
    throw new SolrException(SolrException.ErrorCode.BAD_REQUEST, "Only valid for SolrCloud");
  }

  SyncStrategy syncStrategy = null;
  try (SolrCore core = it.handler.coreContainer.getCore(cname)) {

    if (core != null) {
      syncStrategy = new SyncStrategy(core.getCoreContainer());

      Map<String, Object> props = new HashMap<>();
      props.put(ZkStateReader.BASE_URL_PROP, zkController.getBaseUrl());
      props.put(ZkStateReader.CORE_NAME_PROP, cname);
      props.put(ZkStateReader.NODE_NAME_PROP, zkController.getNodeName());

      boolean success = syncStrategy.sync(zkController, core, new ZkNodeProps(props), true).isSuccess();
      // solrcloud_debug
      if (log.isDebugEnabled()) {
        try {
          RefCounted<SolrIndexSearcher> searchHolder = core
              .getNewestSearcher(false);
          SolrIndexSearcher searcher = searchHolder.get();
          try {
            if (log.isDebugEnabled()) {
              log.debug("{} synched {}", core.getCoreContainer().getZkController().getNodeName()
                  , searcher.count(new MatchAllDocsQuery()));
            }
          } finally {
            searchHolder.decref();
          }
        } catch (Exception e) {
          log.debug("Error in solrcloud_debug block", e);
        }
      }
      if (!success) {
        throw new SolrException(SolrException.ErrorCode.SERVER_ERROR, "Sync Failed");
      }
    } else {
      SolrException.log(log, "Could not find core to call sync:" + cname);
    }
  } finally {
    // no recoveryStrat close for now
    if (syncStrategy != null) {
      syncStrategy.close();
    }
  }
}
 

/**
 * Adds the given Throwable's message to the given NamedList.
 * <p>
 * If the response code is not a regular code, the Throwable's
 * stack trace is both logged and added to the given NamedList.
 * <p>
 * Status codes less than 100 are adjusted to be 500.
 */
@SuppressWarnings({"unchecked"})
public static int getErrorInfo(Throwable ex, @SuppressWarnings({"rawtypes"})NamedList info, Logger log) {
  int code = 500;
  if (ex instanceof SolrException) {
    SolrException solrExc = (SolrException)ex;
    code = solrExc.code();
    NamedList<String> errorMetadata = solrExc.getMetadata();
    if (errorMetadata == null) {
      errorMetadata = new NamedList<>();
    }
    errorMetadata.add(SolrException.ERROR_CLASS, ex.getClass().getName());
    errorMetadata.add(SolrException.ROOT_ERROR_CLASS, SolrException.getRootCause(ex).getClass().getName());
    info.add("metadata", errorMetadata);
    if (ex instanceof ApiBag.ExceptionWithErrObject) {
      ApiBag.ExceptionWithErrObject exception = (ApiBag.ExceptionWithErrObject) ex;
      info.add("details", exception.getErrs() );
    }
  }
  
  for (Throwable th = ex; th != null; th = th.getCause()) {
    String msg = th.getMessage();
    if (msg != null) {
      info.add("msg", msg);
      break;
    }
  }
  
  // For any regular code, don't include the stack trace
  if (code == 500 || code < 100) {
    StringWriter sw = new StringWriter();
    ex.printStackTrace(new PrintWriter(sw));
    SolrException.log(log, null, ex);
    info.add("trace", sw.toString());

    // non standard codes have undefined results with various servers
    if (code < 100) {
      log.warn("invalid return code: {}", code);
      code = 500;
    }
  }
  
  info.add("code", code);
  return code;
}
 

/** 
 * Validates a query matches some XPath test expressions
 * 
 * @param request a URL path with optional query params, e.g. "/schema/fields?fl=id,_version_" 
 */
public static void assertQ(String request, String... tests) {
  try {
    int queryStartPos = request.indexOf('?');
    String query;
    String path;
    if (-1 == queryStartPos) {
      query = "";
      path = request;
    } else {
      query = request.substring(queryStartPos + 1);
      path = request.substring(0, queryStartPos);
    }
    if ( ! query.matches(".*wt=schema\\.xml.*")) { // don't overwrite wt=schema.xml
      query = setParam(query, "wt", "xml");
    }
    request = path + '?' + setParam(query, "indent", "on");

    String response = restTestHarness.query(request);

    // TODO: should the facet handling below be converted to parse the URL?
    /*
    if (req.getParams().getBool("facet", false)) {
      // add a test to ensure that faceting did not throw an exception
      // internally, where it would be added to facet_counts/exception
      String[] allTests = new String[tests.length+1];
      System.arraycopy(tests,0,allTests,1,tests.length);
      allTests[0] = "*[count(//lst[@name='facet_counts']/*[@name='exception'])=0]";
      tests = allTests;
    }
    */

    String results = TestHarness.validateXPath(response, tests);

    if (null != results) {
      String msg = "REQUEST FAILED: xpath=" + results
          + "\n\txml response was: " + response
          + "\n\trequest was:" + request;

      log.error(msg);
      throw new RuntimeException(msg);
    }

  } catch (XPathExpressionException e1) {
    throw new RuntimeException("XPath is invalid", e1);
  } catch (Exception e2) {
    SolrException.log(log, "REQUEST FAILED: " + request, e2);
    throw new RuntimeException("Exception during query", e2);
  }
}