C++ arc::Logger类代码示例

namespace ArcSHCLegacy {

static Arc::Logger logger(Arc::Logger::getRootLogger(),"AuthUser");

int AuthUser::match_file(const char* line) {
  std::list<std::string> tokens;
  Arc::tokenize(line, tokens, " ", "\"", "\"");
  for(std::list<std::string>::iterator s = tokens.begin();s!=tokens.end();++s) {
    std::ifstream f(s->c_str());
    if(!f.is_open()) {
      logger.msg(Arc::ERROR, "Failed to read file %s", *s);
      return AAA_FAILURE;
    };
    for(;f.good();) {
      std::string buf;
      getline(f,buf);
      int res = evaluate(buf.c_str());
      if(res != AAA_NO_MATCH) {
        f.close();
        return res;
      };
    };
    f.close();
  };
  return AAA_NO_MATCH;
}

} // namespace ArcSHCLegacy

int main(int argc, char **argv) {

  setlocale(LC_ALL, "");

  Arc::LogStream logcerr(std::cerr);
  logcerr.setFormat(Arc::ShortFormat);
  Arc::Logger::getRootLogger().addDestination(logcerr);
  Arc::Logger::getRootLogger().setThreshold(Arc::WARNING);

  Arc::ArcLocation::Init(argv[0]);

  Arc::OptionParser options(istring("url"),
                            istring("The arcls command is used for listing "
                                    "files in grid storage elements "
                                    "and file\nindex catalogues."));

  bool longlist = false;
  options.AddOption('l', "long", istring("long format (more information)"),
                    longlist);

  bool locations = false;
  options.AddOption('L', "locations", istring("show URLs of file locations"),
                    locations);

  bool metadata = false;
  options.AddOption('m', "metadata", istring("display all available metadata"),
        metadata);

  bool infinite_recursion = false;
  options.AddOption('r', "recursive",
                    istring("operate recursively"),
                    infinite_recursion);

  int recursion = 0;
  options.AddOption('D', "depth",
                    istring("operate recursively up to specified level"),
                    istring("level"), recursion);

  bool nolist = false;
  options.AddOption('n', "nolist", istring("show only description of requested object, do not list content of directories"),
        nolist);

  bool forcelist = false;
  options.AddOption('f', "forcelist", istring("treat requested object as directory and always try to list content"),
        forcelist);

  bool checkaccess = false;
  options.AddOption('c', "checkaccess", istring("check readability of object, does not show any information about object"),
        checkaccess);

  bool show_plugins = false;
  options.AddOption('P', "listplugins",
                    istring("list the available plugins (protocols supported)"),
                    show_plugins);

  int timeout = 20;
  options.AddOption('t', "timeout", istring("timeout in seconds (default 20)"),
                    istring("seconds"), timeout);

  std::string conffile;
  options.AddOption('z', "conffile",
                    istring("configuration file (default ~/.arc/client.conf)"),
                    istring("filename"), conffile);

  std::string debug;
  options.AddOption('d', "debug",
                    istring("FATAL, ERROR, WARNING, INFO, VERBOSE or DEBUG"),
                    istring("debuglevel"), debug);

  bool version = false;
  options.AddOption('v', "version", istring("print version information"),
                    version);

  std::list<std::string> params = options.Parse(argc, argv);

  if (version) {
    std::cout << Arc::IString("%s version %s", "arcls", VERSION) << std::endl;
    return 0;
  }

  // If debug is specified as argument, it should be set before loading the configuration.
  if (!debug.empty())
    Arc::Logger::getRootLogger().setThreshold(Arc::string_to_level(debug));

  if (show_plugins) {
    std::list<Arc::ModuleDesc> modules;
    Arc::PluginsFactory pf(Arc::BaseConfig().MakeConfig(Arc::Config()).Parent());
    pf.scan(Arc::FinderLoader::GetLibrariesList(), modules);
    Arc::PluginsFactory::FilterByKind("HED:DMC", modules);

    std::cout << Arc::IString("Protocol plugins available:") << std::endl;
    for (std::list<Arc::ModuleDesc>::iterator itMod = modules.begin();
         itMod != modules.end(); itMod++) {
      for (std::list<Arc::PluginDesc>::iterator itPlug = itMod->plugins.begin();
           itPlug != itMod->plugins.end(); itPlug++) {
        std::cout << "  " << itPlug->name << " - " << itPlug->description << std::endl;
      }
    }
    return 0;
  }
//.........这里部分代码省略.........

FileNode::FileNode(char* dirname,char* plugin,std::istream &cfile,userspec_t &user) {
  plug=NULL;
  init=NULL;
  point=std::string(dirname);
  plugname=std::string(plugin);
//    handle=dlopen(plugin,RTLD_LAZY);
  handle=dlopen(plugin,RTLD_NOW);
  if(!handle) {
    logger.msg(Arc::ERROR, dlerror());
    logger.msg(Arc::ERROR, "Can't load plugin %s for access point %s", plugin, dirname);
    return;
  };
  init=(plugin_init_t)dlsym(handle,"init");
  if(init == NULL) {
    logger.msg(Arc::ERROR, "Plugin %s for access point %s is broken.", plugin, dirname);
    dlclose(handle); handle=NULL; return;
  };
  if((plug=init(cfile,user,*this)) == NULL) {
    logger.msg(Arc::ERROR, "Plugin %s for access point %s is broken.", plugin, dirname);
    dlclose(handle); handle=NULL; init=NULL; return;
  };
  if(plug->acquire() != 1) {
    logger.msg(Arc::ERROR, "Plugin %s for access point %s acquire failed (should never happen).", plugin, dirname);
    delete plug; dlclose(handle); handle=NULL; init=NULL; plug=NULL; return;
  };
}

FileNode& FileNode::operator= (const FileNode &node) {
  logger.msg(Arc::VERBOSE, "FileNode: operator= (%s <- %s) %lu <- %lu", point, node.point, (unsigned long int)this, (unsigned long int)(&node));
  if(plug) if(plug->release() == 0) {
    logger.msg(Arc::VERBOSE, "Copying with dlclose");
    delete plug; dlclose(handle); handle=NULL; init=NULL; plug=NULL;
  };
  point=node.point; plugname=node.plugname;
  plug=node.plug; handle=node.handle;
  return *this;
}

int FilePlugin::release(void) {
  count--;
  if(count < 0) {
    logger.msg(Arc::WARNING, "FilePlugin: more unload than load");
    count=0;
  };
  return count;
}

int AuthUser::match_ldap(const char* line) {
#ifdef HAVE_LDAP
  for(;;) {
    std::string u("");
    int n = gridftpd::input_escaped_string(line,u,' ','"');
    if(n == 0) break;
    line+=n;
	try {
      Arc::URL url(u.c_str());
      if(url.Protocol() != "ldap") return AAA_FAILURE;
      std::string usersn("");
      gridftpd::LdapQuery ldap(url.Host(), url.Port(), false, usersn);
      logger.msg(Arc::INFO, "Connecting to %s:%i", url.Host(), url.Port());
      logger.msg(Arc::INFO, "Quering at %s", url.Path());
      std::vector<std::string> attrs; attrs.push_back("description");
      try {
        ldap.Query(url.Path(),"",attrs,gridftpd::LdapQuery::onelevel);
      } catch (gridftpd::LdapQueryError& e) {
        logger.msg(Arc::ERROR, "Failed to query LDAP server %s", u);
        return AAA_FAILURE;
      };
      result_t r(subject.c_str());
      try {
        ldap.Result(&result_callback,&r) ;
      } catch (gridftpd::LdapQueryError& e) {
        logger.msg(Arc::ERROR, "Failed to get results from LDAP server %s", u);
        return AAA_FAILURE;
      };
      if(r.decision==AAA_POSITIVE_MATCH) {  // just a placeholder
        default_voms_=NULL;
        default_vo_=NULL;
        default_role_=NULL;
        default_capability_=NULL;
        default_vgroup_=NULL;
      }; 
      return r.decision;
    } catch (std::exception& e) {
      return AAA_FAILURE;
    };
  };
  return AAA_NO_MATCH;
#else
  logger.msg(Arc::ERROR, "LDAP authorization is not supported");
  return AAA_FAILURE;
#endif
}

void GridFTP_Commands::data_connect_store_callback(void* arg,globus_ftp_control_handle_t*,unsigned int /* stripendx */,globus_bool_t /* reused */,globus_object_t *error) {
  GridFTP_Commands *it = (GridFTP_Commands*)arg;
  logger.msg(Arc::VERBOSE, "data_connect_store_callback");
  globus_thread_blocking_will_block();
  globus_mutex_lock(&(it->data_lock));
  it->time_spent_disc=0;
  it->time_spent_network=0;
  it->last_action_time=time(NULL);
  logger.msg(Arc::VERBOSE, "Data channel connected (store)");
  if(it->check_abort(error)) {
    it->froot.close(false);
    globus_mutex_unlock(&(it->data_lock)); return;
  };
  it->data_eof = false;
  /* make buffers */
  it->compute_data_buffer();
  if(!(it->allocate_data_buffer())) {
    it->froot.close(false);
    it->force_abort(); globus_mutex_unlock(&(it->data_lock)); return;
  };
  /* register all available buffers */
  it->data_callbacks=0;
  globus_result_t res = GLOBUS_SUCCESS;
  for(unsigned int i = 0;i<it->data_buffer_num;i++) {
    if(!((it->data_buffer)[i].data)) continue;
    struct timezone tz;
    gettimeofday(&(it->data_buffer[i].time_last),&tz);
    res=globus_ftp_control_data_read(&(it->handle),
            (globus_byte_t*)(it->data_buffer[i].data),
            it->data_buffer_size,
            &data_store_callback,it);
    if(res==GLOBUS_SUCCESS) { it->data_callbacks++; }
    else { break; };
  };
  if(it->data_callbacks==0) {
    logger.msg(Arc::ERROR, "Failed to register any buffer");
    if(res != GLOBUS_SUCCESS) {
      logger.msg(Arc::ERROR, "Globus error: %s", Arc::GlobusResult(res).str());
    };
    it->froot.close(false);
    it->free_data_buffer();
    it->force_abort(); globus_mutex_unlock(&(it->data_lock)); return;
  };
  globus_mutex_unlock(&(it->data_lock)); return;
}

/* *** list transfer callbacks *** */
void GridFTP_Commands::list_retrieve_callback(void* arg,globus_ftp_control_handle_t*,globus_object_t *error,globus_byte_t* /* buffer */,globus_size_t /* length */,globus_off_t /* offset */,globus_bool_t /* eof */) {
  GridFTP_Commands *it = (GridFTP_Commands*)arg;
  globus_mutex_lock(&(it->data_lock));
  it->last_action_time=time(NULL);
  if(it->check_abort(error)) {
    it->free_data_buffer();
    globus_mutex_unlock(&(it->data_lock));
    return;
  };
  globus_bool_t eodf;
  globus_size_t size;
  if(it->dir_list_pointer == it->dir_list.end()) {
    it->virt_offset=0;
    it->transfer_mode=false;
    it->free_data_buffer();
    logger.msg(Arc::VERBOSE, "Closing channel (list)");
    it->send_response("226 Transfer completed.\r\n");
    globus_mutex_unlock(&(it->data_lock));
    return;
  };
  globus_ftp_control_local_send_eof(&(it->handle),GLOBUS_TRUE);
  ++(it->dir_list_pointer);
  if(it->dir_list_pointer == it->dir_list.end()) {
    size=0; eodf=GLOBUS_TRUE;
  }
  else {
    size=make_list_string(*(it->dir_list_pointer),it->list_mode,
                        it->data_buffer[0].data,it->data_buffer_size,
                        it->list_name_prefix.c_str());
    eodf=GLOBUS_FALSE;
  };
  globus_result_t res;
  res=globus_ftp_control_data_write(&(it->handle),
                   (globus_byte_t*)(it->data_buffer[0].data),
                   size,it->list_offset,eodf,
                   &list_retrieve_callback,it);
  if(res != GLOBUS_SUCCESS) {
    it->free_data_buffer();
    it->force_abort();
    globus_mutex_unlock(&(it->data_lock));
    return;
  };
  globus_mutex_unlock(&(it->data_lock));
}

void GridFTP_Commands::list_connect_retrieve_callback(void* arg,globus_ftp_control_handle_t*,unsigned int /* stripendx */,globus_bool_t /* reused */,globus_object_t *error) {
  GridFTP_Commands *it = (GridFTP_Commands*)arg;
  globus_mutex_lock(&(it->data_lock));
  it->last_action_time=time(NULL);
  if(it->check_abort(error)) {
    globus_mutex_unlock(&(it->data_lock));
    return;
  };
  it->data_buffer_size=4096;
  it->data_buffer_num=1;
  if(!it->allocate_data_buffer()) {
    it->force_abort(); globus_mutex_unlock(&(it->data_lock)); return;
  };
  it->dir_list_pointer=it->dir_list.begin();
  globus_size_t size;
  globus_bool_t eodf;
  if(it->dir_list_pointer == it->dir_list.end()) {
    size=0; eodf=GLOBUS_TRUE;
  }
  else {
    size=make_list_string(*(it->dir_list_pointer),it->list_mode,
                         it->data_buffer[0].data,it->data_buffer_size,
                        it->list_name_prefix.c_str());
    eodf=GLOBUS_FALSE;
  };
  it->list_offset = 0;
  logger.msg(Arc::VERBOSE, "Data channel connected (list)");
  globus_ftp_control_local_send_eof(&(it->handle),GLOBUS_TRUE);
  globus_result_t res;
  res=globus_ftp_control_data_write(&(it->handle),
                   (globus_byte_t*)(it->data_buffer[0].data),
                   size,it->list_offset,eodf,
                   &list_retrieve_callback,it);
  if(res != GLOBUS_SUCCESS) {
    it->free_data_buffer();
    it->force_abort();
    globus_mutex_unlock(&(it->data_lock));
    return;
  };
  it->list_offset+=size;
  globus_mutex_unlock(&(it->data_lock));
}

// TODO: In a future accept and store ALL policies. Let it fail at PDP level.
//       Currently code fails immediately if policy not recognized.
//       Alternatively behavior may be configurable.
static bool get_proxy_policy(X509* cert,DelegationMultiSecAttr* sattr) {
  bool result = false;
#ifdef HAVE_OPENSSL_PROXY
  PROXY_CERT_INFO_EXTENSION *pci = (PROXY_CERT_INFO_EXTENSION*)X509_get_ext_d2i(cert,NID_proxyCertInfo,NULL,NULL);
  if(!pci) return true; // No proxy 
  switch (OBJ_obj2nid(pci->proxyPolicy->policyLanguage)) {
    case NID_Independent: { // No rights granted
      // Either such situation should be disallowed or 
      // policy should be generated which granst no right for enything.
      // First option is easier to implement so using it at least yet.
      logger.msg(DEBUG,"Independent proxy - no rights granted");
    }; break; 
    case NID_id_ppl_inheritAll: {
      // All right granted. No additional policies should be enforced.
      logger.msg(DEBUG,"Proxy with all rights inherited");
      result=true;
    }; break;
    case NID_id_ppl_anyLanguage: { // Here we store ARC policy
      // Either this is ARC policy is determined by examining content
      const char* policy_str = (const char *)(pci->proxyPolicy->policy->data);
      int policy_length = pci->proxyPolicy->policy->length;
      if((policy_str == NULL) || (policy_length <= 0)) {
        logger.msg(DEBUG,"Proxy with empty policy  - fail on unrecognized policy");
        break;
      };
      {
        std::string s(policy_str,policy_length);
        logger.msg(DEBUG,"Proxy with specific policy: %s",s);
      };
      result = sattr->Add(policy_str,policy_length);
      if(result) {
        logger.msg(DEBUG,"Proxy with ARC Policy");
      } else {
        logger.msg(DEBUG,"Proxy with unknown policy  - fail on unrecognized policy");
      };
    }; break;
    default: {
      // Unsupported policy - fail
    }; break;
  };
  PROXY_CERT_INFO_EXTENSION_free(pci);
#endif
  return result;
}

static bool arcls(const Arc::URL& dir_url,
           Arc::UserConfig& usercfg,
           bool show_details, // longlist
           bool show_urls,    // locations
           bool show_meta,    // metadata
           bool no_list,      // don't list dirs
           bool force_list,   // force dir list
           bool check_access, // checkaccess
           int recursion,     // recursion 
           int timeout) {     // timeout

  if (!dir_url) {
    logger.msg(Arc::ERROR, "Invalid URL: %s", dir_url.fullstr());
    return false;
  }
  if (dir_url.Protocol() == "urllist") {
    std::list<Arc::URL> dirs = Arc::ReadURLList(dir_url);
    if (dirs.empty()) {
      logger.msg(Arc::ERROR, "Can't read list of locations from file %s",
                 dir_url.Path());
      return false;
    }
    bool r = true;
    for (std::list<Arc::URL>::iterator dir = dirs.begin();
         dir != dirs.end(); dir++) {
      if(!arcls(*dir, usercfg, show_details, show_urls, show_meta,
               no_list, force_list, check_access, recursion, timeout)) r = false;
    }
    return r;
  }

  Arc::DataHandle url(dir_url, usercfg);
  if (!url) {
    logger.msg(Arc::ERROR, "Unsupported URL given");
    return false;
  }
  if (url->RequiresCredentials()) {
    if (usercfg.ProxyPath().empty() ) {
      logger.msg(Arc::ERROR, "Unable to list content of %s: No valid credentials found", dir_url.str());
      return false;
    }
    Arc::Credential holder(usercfg.ProxyPath(), "", "", "");
    if (holder.GetEndTime() < Arc::Time()){
      logger.msg(Arc::ERROR, "Proxy expired");
      logger.msg(Arc::ERROR, "Unable to list content of %s: No valid credentials found", dir_url.str());
      return false;
    }
  }
  url->SetSecure(false);

  if(check_access) {
    std::cout << dir_url << " - ";
    if(url->Check(false)) {
      std::cout << "passed" << std::endl;
      return true;
    } else {
      std::cout << "failed" << std::endl;
      return false;
    }
  }

  Arc::DataPoint::DataPointInfoType verb = (Arc::DataPoint::DataPointInfoType)
                                           (Arc::DataPoint::INFO_TYPE_MINIMAL |
                                            Arc::DataPoint::INFO_TYPE_NAME);
  if(show_urls) verb = (Arc::DataPoint::DataPointInfoType)
                       (verb | Arc::DataPoint::INFO_TYPE_STRUCT);
  if(show_meta) verb = (Arc::DataPoint::DataPointInfoType)
                       (verb | Arc::DataPoint::INFO_TYPE_ALL);
  if(show_details) verb = (Arc::DataPoint::DataPointInfoType)
                          (verb |
                           Arc::DataPoint::INFO_TYPE_TYPE |
                           Arc::DataPoint::INFO_TYPE_TIMES |
                           Arc::DataPoint::INFO_TYPE_CONTENT |
                           Arc::DataPoint::INFO_TYPE_ACCESS); 
  if(recursion > 0) verb = (Arc::DataPoint::DataPointInfoType)
                           (verb | Arc::DataPoint::INFO_TYPE_TYPE);

  Arc::DataStatus res;
  Arc::FileInfo file;
  std::list<Arc::FileInfo> files;

  if(no_list) { // only requested object is queried
    res = url->Stat(file, verb);
    if(res) files.push_back(file);
  } else if(force_list) { // assume it is directory, fail otherwise
    res = url->List(files, verb);
  } else { // try to guess what to do
    res = url->Stat(file, (Arc::DataPoint::DataPointInfoType)(verb | Arc::DataPoint::INFO_TYPE_TYPE));
    if(res && (file.GetType() == Arc::FileInfo::file_type_file)) {
      // If it is file and we are sure, then just report it.
      files.push_back(file);
    } else {
      // If it is dir then we must list it. But if stat failed or
      // if type is undefined there is still chance it is directory.
      Arc::DataStatus res_ = url->List(files, verb);
      if(!res_) {
        // If listing failed maybe simply report previous result if any.
        if(res) {
          files.push_back(file);
        }
//.........这里部分代码省略.........

gss_cred_id_t read_globus_credentials(const std::string& filename) {
  Arc::Credential cred(filename, "", "", "", "", true);
  X509* cert = cred.GetCert();
  STACK_OF(X509)* cchain = cred.GetCertChain();
  EVP_PKEY* key = cred.GetPrivKey();
  globus_gsi_cred_handle_t chandle;
  globus_gsi_cred_handle_init(&chandle, NULL);
  if(cert) globus_gsi_cred_set_cert(chandle, cert);
  if(key) globus_gsi_cred_set_key(chandle, key);
  if(cchain) globus_gsi_cred_set_cert_chain(chandle, cchain);

  gss_cred_id_desc* ccred = (gss_cred_id_desc*)::malloc(sizeof(gss_cred_id_desc));
  if(ccred) {
    ::memset(ccred,0,sizeof(gss_cred_id_desc));
    ccred->cred_handle = chandle; chandle = NULL;
    // cred_usage
    // ssl_context
    X509* identity_cert = NULL;
    if(cert) {
      globus_gsi_cert_utils_cert_type_t ctype = GLOBUS_GSI_CERT_UTILS_TYPE_DEFAULT;
      globus_gsi_cert_utils_get_cert_type(cert,&ctype);
      if(ctype == GLOBUS_GSI_CERT_UTILS_TYPE_EEC) {
        identity_cert = cert;
      };
    };
    if(!identity_cert && cchain) {
      // For compatibility with older globus not using
      //globus_gsi_cert_utils_get_identity_cert(cchain,&identity_cert);
      for(int n = 0; n < sk_X509_num(cchain); ++n) {
        X509* tmp_cert = sk_X509_value(cchain, n);
        if(tmp_cert) {
          globus_gsi_cert_utils_cert_type_t ctype = GLOBUS_GSI_CERT_UTILS_TYPE_DEFAULT;
          globus_gsi_cert_utils_get_cert_type(tmp_cert,&ctype);
          if(ctype == GLOBUS_GSI_CERT_UTILS_TYPE_EEC) {
            identity_cert = tmp_cert;
            break;
          };
        };
      };
    };
    gss_buffer_desc peer_buffer;
    peer_buffer.value = identity_cert;
    peer_buffer.length = identity_cert?sizeof(X509):0;
    OM_uint32 majstat, minstat;
    majstat = gss_import_name(&minstat, &peer_buffer,
                              identity_cert?GLOBUS_GSS_C_NT_X509:GSS_C_NT_ANONYMOUS,
                              &ccred->globusid);
    if (GSS_ERROR(majstat)) {
      logger.msg(Arc::ERROR, "Failed to convert GSI credential to "
         "GSS credential (major: %d, minor: %d)", majstat, minstat);
      majstat = gss_release_cred(&minstat, &ccred);
    };
  } else {
    ccred = GSS_C_NO_CREDENTIAL;
  };
  if(cert) X509_free(cert);
  if(key) EVP_PKEY_free(key);
  if(cchain) sk_X509_pop_free(cchain, X509_free);
  if(chandle) globus_gsi_cred_handle_destroy(chandle);
  return ccred;
}

void GridFTP_Commands::data_store_callback(void* arg,globus_ftp_control_handle_t*,globus_object_t *error,globus_byte_t *buffer,globus_size_t length,globus_off_t offset,globus_bool_t eof) {
  globus_thread_blocking_will_block();
  GridFTP_Commands *it = (GridFTP_Commands*)arg;
  struct timezone tz;
  struct timeval tv;
  gettimeofday(&tv,&tz);
  globus_mutex_lock(&(it->data_lock));
  it->last_action_time=time(NULL);
  logger.msg(Arc::VERBOSE, "Data channel (store) %i %i %i", (int)offset, (int)length, (int)eof);
  it->data_callbacks--;
  if(it->check_abort(error)) {
    if(it->data_callbacks==0){it->free_data_buffer();it->froot.close(false);};
    globus_mutex_unlock(&(it->data_lock)); return;
  };
  if(eof) it->data_eof=true;
  /* find this buffer */
  unsigned int i;
  for(i = 0;i<it->data_buffer_num;i++) {
    if((it->data_buffer)[i].data == (unsigned char*)buffer) break;
  };
  if(i >= it->data_buffer_num) { /* lost buffer - probably memory corruption */
    logger.msg(Arc::ERROR, "data_store_callback: lost buffer");
    it->force_abort();
    if(it->data_callbacks==0){it->free_data_buffer();it->froot.close(false);};
    globus_mutex_unlock(&(it->data_lock)); return;
  };
  unsigned long long int time_diff = 
     (tv.tv_sec-(it->data_buffer[i].time_last.tv_sec))*1000000+
     (tv.tv_usec-(it->data_buffer[i].time_last.tv_usec));
  it->time_spent_network+=time_diff;
  /* write data to file 
     NOTE: it->data_lock is not unlocked here because it->froot.write 
     is not thread safe */
  struct timeval tv_last;
  gettimeofday(&tv_last,&tz);
  if(it->froot.write(it->data_buffer[i].data,
                (it->virt_offset)+offset,length) != 0) {
    logger.msg(Arc::ERROR, "Closing channel (store) due to error: %s", it->froot.error);
    it->force_abort();
    if(it->data_callbacks==0){it->free_data_buffer();it->froot.close(false);};
    globus_mutex_unlock(&(it->data_lock)); return;
  }; 
  gettimeofday(&tv,&tz);
  time_diff=(tv.tv_sec-tv_last.tv_sec)*1000000+(tv.tv_usec-tv_last.tv_usec);
  it->time_spent_disc+=time_diff;
  if(it->data_eof) {
    if(it->data_callbacks==0) {
      logger.msg(Arc::VERBOSE, "Closing channel (store)");
      it->free_data_buffer();
      it->virt_offset=0;
      it->virt_restrict=false;
      it->transfer_mode=false;
      if(it->froot.close() != 0) {
        if(it->froot.error.length()) {
          it->send_response("451 "+it->froot.error+"\r\n");
        } else {
          it->send_response("451 Local error\r\n");
        };
      }
      else {
        logger.msg(Arc::VERBOSE, "Time spent waiting for network: %.3f ms", (float)(it->time_spent_network/1000.0));
        logger.msg(Arc::VERBOSE, "Time spent waiting for disc: %.3f ms", (float)(it->time_spent_disc/1000.0));
        it->send_response("226 Requested file transfer completed\r\n");
      };
    };
    globus_mutex_unlock(&(it->data_lock)); return;
  };
  /* register buffer */
  globus_result_t res;
  gettimeofday(&(it->data_buffer[i].time_last),&tz);
  res=globus_ftp_control_data_read(&(it->handle),
            (globus_byte_t*)(it->data_buffer[i].data),
            it->data_buffer_size,
            &data_store_callback,it);
  if(res != GLOBUS_SUCCESS) {
    /* Because this error can be caused by EOF, abort should not be
       called unless this is last buffer */
    if(it->data_callbacks==0) {
      logger.msg(Arc::ERROR, "Globus error: %s", Arc::GlobusResult(res).str());
      it->force_abort();
      it->free_data_buffer();it->froot.close(false);
    };
    globus_mutex_unlock(&(it->data_lock)); return;
  };
  it->data_callbacks++;
  globus_mutex_unlock(&(it->data_lock)); return;
}