Date: Fri, 11 Oct 2013 21:50:04 +0000 (UTC) From: Alan Somers <asomers@FreeBSD.org> To: src-committers@freebsd.org, svn-src-projects@freebsd.org Subject: svn commit: r256353 - projects/zfsd/head/cddl/sbin/zfsd Message-ID: <201310112150.r9BLo4aT036366@svn.freebsd.org>
next in thread | raw e-mail | index | archive | help
Author: asomers Date: Fri Oct 11 21:50:04 2013 New Revision: 256353 URL: http://svnweb.freebsd.org/changeset/base/256353 Log: Fix a bug in zfsd whereby it won't degrade or fault a drive if the devd socket gets HUPed after the drive's last error. The key was to not discard case files when the socket gets HUPed, because doing so drops their callouts. * When calling CaseFile::PurgeAll (such as happens after the DevD socket gets HUPed), serialize case files before purging them. That way, they can be read back in after the connection to devd is restored and proessing may continue. * Added Callout::TimeRemaining to calculate how much time until any given callout expires. * When registering callouts, compute the timeout value based on the event's timestamp, not the present time. * In CaseFile::Serialize, serialize both m_events and m_tentativeEvents. Tentative events will be prefixed with "tentative " in the serialized file. * In DeSerializeFile, push tentative events and regular events into the corresponding m_events or m_tentativeEvents, as appropriate. * ExtractEvents will timestamp each incoming event with a timestamp=seconds_since_epoch nvpair, if not already present. Added a DevCtlEvent::getTimestamp method to read it. * style: in ZfsDaemon::EventLoop changed fds->XXX to fds[0]. to emphase that fds is an array. * A few minor typo fixes in comments. Submitted by: asomers Approved by: ken (mentor) Sponsored by: Spectra Logic Corporation Modified: projects/zfsd/head/cddl/sbin/zfsd/callout.cc projects/zfsd/head/cddl/sbin/zfsd/callout.h projects/zfsd/head/cddl/sbin/zfsd/case_file.cc projects/zfsd/head/cddl/sbin/zfsd/case_file.h projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.cc projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.h projects/zfsd/head/cddl/sbin/zfsd/zfsd.cc Modified: projects/zfsd/head/cddl/sbin/zfsd/callout.cc ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/callout.cc Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/callout.cc Fri Oct 11 21:50:04 2013 (r256353) @@ -167,3 +167,37 @@ Callout::ExpireCallouts() setitimer(ITIMER_REAL, &timerval, NULL); } } + +timeval +Callout::TimeRemaining() const +{ + /* + * Outline: Add the m_interval for each callout in s_activeCallouts + * ahead of this, except for the first callout. Add to that the result + * of getitimer (That's because the first callout stores its original + * interval setting while the timer is ticking). + */ + itimerval timervalToAlarm; + timeval timeToExpiry; + std::list<Callout *>::iterator it; + + if (! IsPending() ) { + timeToExpiry.tv_sec = INT_MAX; + timeToExpiry.tv_usec = 999999; /*maximum normalized value*/ + return (timeToExpiry); + } + + timerclear(&timeToExpiry); + getitimer(ITIMER_REAL, &timervalToAlarm); + timeval& timeToAlarm = timervalToAlarm.it_value; + timeradd(&timeToExpiry, &timeToAlarm, &timeToExpiry); + + it =s_activeCallouts.begin(); + it++; /*skip the first callout in the list*/ + for (; it != s_activeCallouts.end(); it++) { + timeradd(&timeToExpiry, &(*it)->m_interval, &timeToExpiry); + if ((*it) == this) + break; + } + return (timeToExpiry); +} Modified: projects/zfsd/head/cddl/sbin/zfsd/callout.h ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/callout.h Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/callout.h Fri Oct 11 21:50:04 2013 (r256353) @@ -117,6 +117,17 @@ public: */ bool Reset(const timeval &interval, CalloutFunc_t *func, void *arg); + /** + * \brief Calculate the remaining time until this Callout's timer + * expires. + * + * The return value will be slightly greater than the actual time to + * expiry. + * + * If the callout is not pending, returns INT_MAX. + */ + timeval TimeRemaining() const; + private: /** * All active callouts sorted by expiration time. The callout Modified: projects/zfsd/head/cddl/sbin/zfsd/case_file.cc ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/case_file.cc Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/case_file.cc Fri Oct 11 21:50:04 2013 (r256353) @@ -144,9 +144,17 @@ CaseFile::LogAll() void CaseFile::PurgeAll() { - /* CaseFiles remove themselves from this list on destruction. */ - while (s_activeCases.size() != 0) - delete s_activeCases.front(); + /* + * Serialize casefiles before deleting them so that they can be reread + * and revalidated during BuildCaseFiles. + * CaseFiles remove themselves from this list on destruction. + */ + while (s_activeCases.size() != 0) { + CaseFile *casefile = s_activeCases.front(); + casefile->Serialize(); + delete casefile; + } + } //- CaseFile Public Methods ---------------------------------------------------- @@ -388,9 +396,7 @@ CaseFile::ReEvaluate(const ZfsEvent &eve || event.Value("class") == "ereport.fs.zfs.checksum") { m_tentativeEvents.push_front(event.DeepCopy()); - if (!m_tentativeTimer.IsPending()) - m_tentativeTimer.Reset(s_removeGracePeriod, - OnGracePeriodEnded, this); + RegisterCallout(event); consumed = true; } @@ -399,6 +405,33 @@ CaseFile::ReEvaluate(const ZfsEvent &eve return (consumed || closed); } + +void +CaseFile::RegisterCallout(const DevCtlEvent &event) +{ + timeval now, countdown, elapsed, timestamp, zero, remaining; + gettimeofday(&now, 0); + timestamp = event.GetTimestamp(); + timersub(&now, ×tamp, &elapsed); + timersub(&s_removeGracePeriod, &elapsed, &countdown); + /* + * If countdown is <= zero, Reset the timer to the + * smallest positive time value instead + */ + timerclear(&zero); + if (timercmp(&countdown, &zero, <=)) { + timerclear(&countdown); + countdown.tv_usec = 1; + } + + remaining = m_tentativeTimer.TimeRemaining(); + + if (!m_tentativeTimer.IsPending() + || timercmp(&countdown, &remaining, <)) + m_tentativeTimer.Reset(countdown, OnGracePeriodEnded, this); +} + + bool CaseFile::CloseIfSolved() { @@ -478,7 +511,6 @@ CaseFile::DeSerializeFile(const char *fi string evString; CaseFile *existingCaseFile(NULL); CaseFile *caseFile(NULL); - ifstream *caseStream(NULL); try { uintmax_t poolGUID; @@ -511,8 +543,8 @@ CaseFile::DeSerializeFile(const char *fi .Find(vdevGUID)) == NULL) { /* * Either the pool no longer exists - * of this vdev is no longer a member of - * the pool. + * or this vdev is no longer a member of + * the pool. */ unlink(fullName.c_str()); return; @@ -526,29 +558,58 @@ CaseFile::DeSerializeFile(const char *fi caseFile = new CaseFile(Vdev(zpl.front(), vdevConf)); } - caseStream = new ifstream(fullName.c_str()); - if ( (caseStream == NULL) || (! *caseStream) ) { + ifstream caseStream(fullName.c_str()); + if (! caseStream) { throw ZfsdException("CaseFile::DeSerialize: Unable to " "read %s.\n", fileName); return; } - IstreamReader caseReader(caseStream); + stringstream fakeDevdSocket(stringstream::in + | stringstream::out); + IstreamReader caseReader(&fakeDevdSocket); /* Re-load EventData */ EventBuffer eventBuffer(caseReader); - while (eventBuffer.ExtractEvent(evString)) { - DevCtlEvent *event(DevCtlEvent::CreateEvent(evString)); - if (event != NULL) - caseFile->m_events.push_back(event); + caseStream >> std::noskipws >> std::ws; + while (!caseStream.eof()) { + /* + * Outline: + * read the beginning of a line and check it for + * "tentative". If found, discard "tentative". + * Shove into fakeDevdSocket. + * call ExtractEvent + * continue + */ + DevCtlEventList* destEvents; + string tentFlag("tentative "); + string line; + std::stringbuf lineBuf; + caseStream.get(lineBuf); + caseStream.ignore(); /*discard the newline character*/ + line = lineBuf.str(); + if (line.compare(0, tentFlag.size(), tentFlag) == 0) { + line.erase(0, tentFlag.size()); + destEvents = &caseFile->m_tentativeEvents; + } else { + destEvents = &caseFile->m_events; + } + fakeDevdSocket << line; + fakeDevdSocket << '\n'; + while (eventBuffer.ExtractEvent(evString)) { + DevCtlEvent *event(DevCtlEvent::CreateEvent( + evString)); + if (event != NULL) { + destEvents->push_back(event); + caseFile->RegisterCallout(*event); + } + } } - delete caseStream; + } catch (const ParseException &exp) { exp.Log(evString); if (caseFile != existingCaseFile) delete caseFile; - if (caseStream) - delete caseStream; /* * Since we can't parse the file, unlink it so we don't @@ -560,8 +621,6 @@ CaseFile::DeSerializeFile(const char *fi zfsException.Log(); if (caseFile != existingCaseFile) delete caseFile; - if (caseStream) - delete caseStream; } } @@ -614,6 +673,24 @@ CaseFile::PurgeTentativeEvents() m_tentativeEvents.clear(); } + +void +CaseFile::SerializeEvList(const DevCtlEventList events, int fd, + const char* prefix) const +{ + if (events.empty()) + return; + for (DevCtlEventList::const_iterator curEvent = events.begin(); + curEvent != events.end(); curEvent++) { + const string &eventString((*curEvent)->GetEventString()); + + if (prefix) + write(fd, prefix, strlen(prefix)); + write(fd, eventString.c_str(), eventString.length()); + } +} + + void CaseFile::Serialize() { @@ -625,7 +702,7 @@ CaseFile::Serialize() << "_vdev_" << VdevGUIDString() << ".case"; - if (m_events.empty()) { + if (m_events.empty() && m_tentativeEvents.empty()) { unlink(saveFile.str().c_str()); return; } @@ -636,12 +713,8 @@ CaseFile::Serialize() saveFile.str().c_str()); return; } - for (DevCtlEventList::const_iterator curEvent = m_events.begin(); - curEvent != m_events.end(); curEvent++) { - const string &eventString((*curEvent)->GetEventString()); - - write(fd, eventString.c_str(), eventString.length()); - } + SerializeEvList(m_events, fd); + SerializeEvList(m_tentativeEvents, fd, "tentative "); close(fd); } Modified: projects/zfsd/head/cddl/sbin/zfsd/case_file.h ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/case_file.h Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/case_file.h Fri Oct 11 21:50:04 2013 (r256353) @@ -171,7 +171,12 @@ public: bool ReEvaluate(const ZfsEvent &event); /** - * \breif Close a case if it is no longer relevant. + * \brief Register an itimer callout for the given event, if necessary + */ + void RegisterCallout(const DevCtlEvent &event); + + /** + * \brief Close a case if it is no longer relevant. * * This method deals with cases tracking soft errors. Soft errors * will be discarded should a remove event occur within a short period @@ -210,12 +215,12 @@ protected: static int DeSerializeSelector(const struct dirent *dirEntry); /** - * \brief Given the name of a file containing a serialized CaseFile - * object, create/update an in-core CaseFile object + * \brief Given the name of a file containing serialized events from a + * CaseFile object, create/update an in-core CaseFile object * representing the serialized data. * - * \param fileName The name of a file containing a serialized - * CaseFile object. + * \param fileName The name of a file containing serialized events + * from a CaseFile object. */ static void DeSerializeFile(const char *fileName); @@ -248,6 +253,15 @@ protected: */ void Serialize(); + /** + * \brief Serializes the supplied event list and writes it to fd + * + * \param prefix If not NULL, this prefix will be prepended to + * every event in the file. + */ + void SerializeEvList(const DevCtlEventList events, int fd, + const char* prefix=NULL) const; + /** * \brief Unconditionally close a CaseFile. */ Modified: projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.cc ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.cc Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.cc Fri Oct 11 21:50:04 2013 (r256353) @@ -250,6 +250,23 @@ DevCtlEvent::Process() const { } +timeval +DevCtlEvent::GetTimestamp() const +{ + timeval tv_timestamp; + struct tm tm_timestamp; + + if ( ! Contains("timestamp") ) { + throw ZfsdException("Event contains no timestamp: %s", + m_eventString.c_str()); + } + strptime(Value(string("timestamp")).c_str(), "%s", &tm_timestamp); + tv_timestamp.tv_sec = mktime(&tm_timestamp); + tv_timestamp.tv_usec = 0; + return (tv_timestamp); +} + + //- DevCtlEvent Protected Methods ---------------------------------------------- DevCtlEvent::DevCtlEvent(Type type, NVPairMap &map, const string &eventString) : m_type(type), Modified: projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.h ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.h Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/dev_ctl_event.h Fri Oct 11 21:50:04 2013 (r256353) @@ -158,7 +158,7 @@ typedef map<string, string> NVPairMap; * * All name => value data for events can be accessed via the Contains() * and Value() methods. name => value pairs for data not explicitly - * recieved as a a name => value pair are synthesized during parsing. For + * recieved as a name => value pair are synthesized during parsing. For * example, ATTACH and DETACH events have "device-name" and "parent" * name => value pairs added. */ @@ -276,6 +276,11 @@ public: */ virtual void Process() const; + /** + * Get the time that the event was created + */ + timeval GetTimestamp() const; + protected: /** Table entries used to map a type to a user friendly string. */ struct EventTypeRecord @@ -353,7 +358,8 @@ private: /** * Ingest event data from the supplied string. * - * \param eventString The string of devd event data to parse. + * \param[in] eventString The string of devd event data to parse. + * \param[out] nvpairs Returns the parsed data */ static void ParseEventString(Type type, const string &eventString, NVPairMap &nvpairs); Modified: projects/zfsd/head/cddl/sbin/zfsd/zfsd.cc ============================================================================== --- projects/zfsd/head/cddl/sbin/zfsd/zfsd.cc Fri Oct 11 21:47:17 2013 (r256352) +++ projects/zfsd/head/cddl/sbin/zfsd/zfsd.cc Fri Oct 11 21:50:04 2013 (r256353) @@ -143,6 +143,11 @@ EventBuffer::EventBuffer(Reader& reader) bool EventBuffer::ExtractEvent(string &eventString) { + stringstream tsField; + timeval now; + + gettimeofday(&now, NULL); + tsField << " timestamp=" << now.tv_sec; while (UnParsed() > 0 || Fill()) { @@ -160,7 +165,7 @@ EventBuffer::ExtractEvent(string &eventS size_t eventLen(strcspn(nextEvent, s_eventEndTokens)); if (!m_synchronized) { - /* Discard data until an end token is read. */ + /* Discard data until an end token is read. */ if (nextEvent[eventLen] != '\0') m_synchronized = true; m_nextEventOffset += eventLen; @@ -205,6 +210,17 @@ EventBuffer::ExtractEvent(string &eventS "Truncated %d characters from event.", eventLen - fieldEnd); } + + /* + * Add a timestamp as the final field of the event if it is + * not already present. + */ + if ( eventString.find("timestamp=") == string::npos) { + eventString.insert( + eventString.find_last_not_of('\n') + 1, + tsField.str()); + } + return (true); } return (false); @@ -653,13 +669,13 @@ ZfsDaemon::EventLoop() RescanSystem(); } - if ((fds->revents & POLLERR) != 0) { + if ((fds[0].revents & POLLERR) != 0) { /* Try reconnecting. */ syslog(LOG_INFO, "Error on socket. Disconnecting."); break; } - if ((fds->revents & POLLHUP) != 0) { + if ((fds[0].revents & POLLHUP) != 0) { /* Try reconnecting. */ syslog(LOG_INFO, "Hup on socket. Disconnecting."); break;
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201310112150.r9BLo4aT036366>