repl5_inc_protocol.c 104 KB

12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028102910301031103210331034103510361037103810391040104110421043104410451046104710481049105010511052105310541055105610571058105910601061106210631064106510661067106810691070107110721073107410751076107710781079108010811082108310841085108610871088108910901091109210931094109510961097109810991100110111021103110411051106110711081109111011111112111311141115111611171118111911201121112211231124112511261127112811291130113111321133113411351136113711381139114011411142114311441145114611471148114911501151115211531154115511561157115811591160116111621163116411651166116711681169117011711172117311741175117611771178117911801181118211831184118511861187118811891190119111921193119411951196119711981199120012011202120312041205120612071208120912101211121212131214121512161217121812191220122112221223122412251226122712281229123012311232123312341235123612371238123912401241124212431244124512461247124812491250125112521253125412551256125712581259126012611262126312641265126612671268126912701271127212731274127512761277127812791280128112821283128412851286128712881289129012911292129312941295129612971298129913001301130213031304130513061307130813091310131113121313131413151316131713181319132013211322132313241325132613271328132913301331133213331334133513361337133813391340134113421343134413451346134713481349135013511352135313541355135613571358135913601361136213631364136513661367136813691370137113721373137413751376137713781379138013811382138313841385138613871388138913901391139213931394139513961397139813991400140114021403140414051406140714081409141014111412141314141415141614171418141914201421142214231424142514261427142814291430143114321433143414351436143714381439144014411442144314441445144614471448144914501451145214531454145514561457145814591460146114621463146414651466146714681469147014711472147314741475147614771478147914801481148214831484148514861487148814891490149114921493149414951496149714981499150015011502150315041505150615071508150915101511151215131514151515161517151815191520152115221523152415251526152715281529153015311532153315341535153615371538153915401541154215431544154515461547154815491550155115521553155415551556155715581559156015611562156315641565156615671568156915701571157215731574157515761577157815791580158115821583158415851586158715881589159015911592159315941595159615971598159916001601160216031604160516061607160816091610161116121613161416151616161716181619162016211622162316241625162616271628162916301631163216331634163516361637163816391640164116421643164416451646164716481649165016511652165316541655165616571658165916601661166216631664166516661667166816691670167116721673167416751676167716781679168016811682168316841685168616871688168916901691169216931694169516961697169816991700170117021703170417051706170717081709171017111712171317141715171617171718171917201721172217231724172517261727172817291730173117321733173417351736173717381739174017411742174317441745174617471748174917501751175217531754175517561757175817591760176117621763176417651766176717681769177017711772177317741775177617771778177917801781178217831784178517861787178817891790179117921793179417951796179717981799180018011802180318041805180618071808180918101811181218131814181518161817181818191820182118221823182418251826182718281829183018311832183318341835183618371838183918401841184218431844184518461847184818491850185118521853185418551856185718581859186018611862186318641865186618671868186918701871187218731874187518761877187818791880188118821883188418851886188718881889189018911892189318941895189618971898189919001901190219031904190519061907190819091910191119121913191419151916191719181919192019211922192319241925192619271928192919301931193219331934193519361937193819391940194119421943194419451946194719481949195019511952195319541955195619571958195919601961196219631964196519661967196819691970197119721973197419751976197719781979198019811982198319841985198619871988198919901991199219931994199519961997199819992000200120022003200420052006200720082009201020112012201320142015201620172018201920202021202220232024202520262027202820292030203120322033203420352036203720382039204020412042204320442045204620472048204920502051205220532054205520562057205820592060206120622063206420652066206720682069207020712072207320742075207620772078207920802081208220832084208520862087208820892090209120922093209420952096209720982099210021012102210321042105210621072108210921102111211221132114211521162117211821192120212121222123212421252126212721282129213021312132213321342135213621372138213921402141214221432144214521462147214821492150215121522153215421552156215721582159216021612162216321642165216621672168216921702171217221732174217521762177217821792180218121822183218421852186218721882189219021912192219321942195219621972198219922002201220222032204220522062207220822092210221122122213221422152216221722182219222022212222222322242225222622272228222922302231223222332234223522362237223822392240224122422243224422452246224722482249225022512252225322542255225622572258225922602261226222632264226522662267226822692270227122722273227422752276227722782279228022812282228322842285228622872288228922902291229222932294229522962297229822992300230123022303230423052306230723082309231023112312231323142315231623172318231923202321232223232324232523262327232823292330233123322333233423352336233723382339234023412342234323442345234623472348234923502351235223532354235523562357235823592360236123622363236423652366236723682369237023712372237323742375237623772378237923802381238223832384238523862387238823892390239123922393239423952396239723982399240024012402240324042405240624072408240924102411
  1. /** BEGIN COPYRIGHT BLOCK
  2. * Copyright (C) 2001 Sun Microsystems, Inc. Used by permission.
  3. * Copyright (C) 2005 Red Hat, Inc.
  4. * All rights reserved.
  5. *
  6. * License: GPL (version 3 or any later version).
  7. * See LICENSE for details.
  8. * END COPYRIGHT BLOCK **/
  9. #ifdef HAVE_CONFIG_H
  10. #include <config.h>
  11. #endif
  12. /* repl5_inc_protocol.c */
  13. /*
  14. The Prot_Incremental object implements the DS 5.0 multi-master incremental
  15. replication protocol.
  16. Stuff to do:
  17. - Need to figure out how asynchronous events end up in here. They are:
  18. - entry updated in replicated area.
  19. - backoff timeout
  20. - enter/leave.
  21. Perhaps these events should be properties of the main protocol.
  22. */
  23. #include <plstr.h>
  24. #include "repl5.h"
  25. #include "repl5_ruv.h"
  26. #include "repl5_prot_private.h"
  27. #include "cl5_api.h"
  28. #include "slapi-plugin.h"
  29. extern int slapi_log_urp;
  30. /*** from proto-slap.h ***/
  31. void ava_done(struct ava *ava);
  32. typedef struct repl5_inc_private
  33. {
  34. char *ruv; /* RUV on remote replica (use diff type for this? - ggood */
  35. Backoff_Timer *backoff;
  36. Repl_Protocol *rp;
  37. PRLock *lock;
  38. PRUint32 eventbits;
  39. } repl5_inc_private;
  40. /* Structures used to communicate with the result reading thread */
  41. #ifndef UIDSTR_SIZE
  42. #define UIDSTR_SIZE 35 /* size of the string representation of the id */
  43. #endif
  44. typedef struct repl5_inc_operation
  45. {
  46. int ldap_message_id;
  47. unsigned long operation_type;
  48. char csn_str[CSN_STRSIZE];
  49. char uniqueid[UIDSTR_SIZE + 1];
  50. ReplicaId replica_id;
  51. struct repl5_inc_operation *next;
  52. } repl5_inc_operation;
  53. typedef struct result_data
  54. {
  55. Private_Repl_Protocol *prp;
  56. int rc;
  57. PRLock *lock; /* Lock to protect access to this structure, the message id list and to force memory barriers */
  58. PRThread *result_tid; /* The async result thread */
  59. repl5_inc_operation *operation_list_head; /* List of IDs for outstanding operations */
  60. repl5_inc_operation *operation_list_tail; /* List of IDs for outstanding operations */
  61. int abort; /* Flag used to tell the sending thread asyncronously that it should abort (because an error came up in a result) */
  62. PRUint32 num_changes_sent;
  63. int stop_result_thread; /* Flag used to tell the result thread to exit */
  64. int last_message_id_sent;
  65. int last_message_id_received;
  66. int flowcontrol_detection;
  67. int result; /* The UPDATE_TRANSIENT_ERROR etc */
  68. int WaitForAsyncResults;
  69. time_t abort_time;
  70. } result_data;
  71. /* Various states the incremental protocol can pass through */
  72. #define STATE_START 0 /* ONREPL - should we rename this - we don't use it just to start up? */
  73. #define STATE_WAIT_WINDOW_OPEN 1
  74. #define STATE_WAIT_CHANGES 2
  75. #define STATE_READY_TO_ACQUIRE 3
  76. #define STATE_BACKOFF_START 4 /* ONREPL - can we combine BACKOFF_START and BACKOFF states? */
  77. #define STATE_BACKOFF 5
  78. #define STATE_SENDING_UPDATES 6
  79. #define STATE_STOP_FATAL_ERROR 7
  80. #define STATE_STOP_FATAL_ERROR_PART2 8
  81. #define STATE_STOP_NORMAL_TERMINATION 9
  82. /* Events (synchronous and asynchronous; these are bits) */
  83. #define EVENT_WINDOW_OPENED 1
  84. #define EVENT_WINDOW_CLOSED 2
  85. #define EVENT_TRIGGERING_CRITERIA_MET 4 /* ONREPL - should we rename this to EVENT_CHANGE_AVAILABLE */
  86. #define EVENT_BACKOFF_EXPIRED 8
  87. #define EVENT_REPLICATE_NOW 16
  88. #define EVENT_PROTOCOL_SHUTDOWN 32
  89. #define EVENT_AGMT_CHANGED 64
  90. #define UPDATE_NO_MORE_UPDATES 201
  91. #define UPDATE_TRANSIENT_ERROR 202
  92. #define UPDATE_FATAL_ERROR 203
  93. #define UPDATE_SCHEDULE_WINDOW_CLOSED 204
  94. #define UPDATE_CONNECTION_LOST 205
  95. #define UPDATE_TIMEOUT 206
  96. #define UPDATE_YIELD 207
  97. /* Return codes from examine_update_vector */
  98. #define EXAMINE_RUV_PRISTINE_REPLICA 401
  99. #define EXAMINE_RUV_GENERATION_MISMATCH 402
  100. #define EXAMINE_RUV_REPLICA_TOO_OLD 403
  101. #define EXAMINE_RUV_OK 404
  102. #define EXAMINE_RUV_PARAM_ERROR 405
  103. #define MAX_CHANGES_PER_SESSION 10000
  104. /*
  105. * Maximum time to wait between replication sessions. If we
  106. * don't see any updates for a period equal to this interval,
  107. * we go ahead and start a replication session, just to be safe
  108. */
  109. #define MAX_WAIT_BETWEEN_SESSIONS PR_SecondsToInterval(60 * 5) /* 5 minutes */
  110. /*
  111. * tests if the protocol has been shutdown and we need to quit
  112. * event_occurred resets the bits in the bit flag, so whoever tests for shutdown
  113. * resets the flags, so the next one who tests for shutdown won't get it, so we
  114. * also look at the terminate flag
  115. */
  116. #define PROTOCOL_IS_SHUTDOWN(prp) (event_occurred(prp, EVENT_PROTOCOL_SHUTDOWN) || prp->terminate)
  117. /* mods should be LDAPMod **mods */
  118. #define MODS_ARE_EMPTY(mods) ((mods == NULL) || (mods[0] == NULL))
  119. /* Forward declarations */
  120. static PRUint32 event_occurred(Private_Repl_Protocol *prp, PRUint32 event);
  121. static void reset_events(Private_Repl_Protocol *prp);
  122. static void protocol_sleep(Private_Repl_Protocol *prp, PRIntervalTime duration);
  123. static int send_updates(Private_Repl_Protocol *prp, RUV *ruv, PRUint32 *num_changes_sent);
  124. static void repl5_inc_backoff_expired(time_t timer_fire_time, void *arg);
  125. static int examine_update_vector(Private_Repl_Protocol *prp, RUV *ruv);
  126. static const char *state2name(int state);
  127. static const char *event2name(int event);
  128. static const char *op2string(int op);
  129. static int repl5_inc_update_from_op_result(Private_Repl_Protocol *prp, ConnResult replay_crc, int connection_error, char *csn_str, char *uniqueid, ReplicaId replica_id, int *finished, PRUint32 *num_changes_sent);
  130. /* Push a newly sent operation onto the tail of the list */
  131. static void
  132. repl5_int_push_operation(result_data *rd, repl5_inc_operation *it)
  133. {
  134. repl5_inc_operation *tail = NULL;
  135. PR_Lock(rd->lock);
  136. tail = rd->operation_list_tail;
  137. if (tail) {
  138. tail->next = it;
  139. }
  140. if (NULL == rd->operation_list_head) {
  141. rd->operation_list_head = it;
  142. }
  143. rd->operation_list_tail = it;
  144. PR_Unlock(rd->lock);
  145. }
  146. /* Pop the next operation in line to respond from the list */
  147. /* The caller is expected to free the operation item */
  148. static repl5_inc_operation *
  149. repl5_inc_pop_operation(result_data *rd)
  150. {
  151. repl5_inc_operation *head = NULL;
  152. repl5_inc_operation *ret = NULL;
  153. PR_Lock(rd->lock);
  154. head = rd->operation_list_head;
  155. if (head) {
  156. ret = head;
  157. rd->operation_list_head = head->next;
  158. if (rd->operation_list_tail == head) {
  159. rd->operation_list_tail = NULL;
  160. }
  161. }
  162. PR_Unlock(rd->lock);
  163. return ret;
  164. }
  165. static void
  166. repl5_inc_op_free(repl5_inc_operation *op)
  167. {
  168. slapi_ch_free((void **)&op);
  169. }
  170. static repl5_inc_operation *
  171. repl5_inc_operation_new(void)
  172. {
  173. repl5_inc_operation *ret = NULL;
  174. ret = (repl5_inc_operation *)slapi_ch_calloc(1, sizeof(repl5_inc_operation));
  175. return ret;
  176. }
  177. /* Called when in compatibility mode, to get the next result from the wire
  178. * The operation thread will not send a second operation until it has read the
  179. * previous result. */
  180. static int
  181. repl5_inc_get_next_result(result_data *rd)
  182. {
  183. ConnResult conres = 0;
  184. int message_id = 0;
  185. /* Wait on the next result */
  186. conres = conn_read_result(rd->prp->conn, &message_id);
  187. /* Return it to the caller */
  188. return conres;
  189. }
  190. #if NEEDED_FOR_DEBUGGING
  191. static void
  192. repl5_inc_log_operation_failure(int operation_code, int ldap_error, char *ldap_error_string, const char *agreement_name)
  193. {
  194. char *op_string = slapi_op_type_to_string(operation_code);
  195. slapi_log_err(SLAPI_LOG_DEBUG, repl_plugin_name,
  196. "repl5_inc_log_operation_failure - %s: Received error %d: %s for %s operation\n",
  197. agreement_name,
  198. ldap_error, ldap_error_string ? ldap_error_string : "NULL",
  199. op_string ? op_string : "NULL");
  200. }
  201. #endif
  202. /* Thread that collects results from async operations sent to the consumer */
  203. static void
  204. repl5_inc_result_threadmain(void *param)
  205. {
  206. result_data *rd = (result_data *)param;
  207. ConnResult conres = 0;
  208. Repl_Connection *conn = rd->prp->conn;
  209. int finished = 0;
  210. int message_id = 0;
  211. int yield_session = 0;
  212. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "repl5_inc_result_threadmain - Starting\n");
  213. while (!finished) {
  214. LDAPControl **returned_controls = NULL;
  215. repl5_inc_operation *op = NULL;
  216. ReplicaId replica_id = 0;
  217. char *csn_str = NULL;
  218. char *uniqueid = NULL;
  219. char *ldap_error_string = NULL;
  220. time_t time_now = 0;
  221. time_t start_time = slapi_current_utc_time();
  222. int connection_error = 0;
  223. int operation_code = 0;
  224. int backoff_time = 1;
  225. /* Read the next result */
  226. /* We call the get result function with a short timeout (non-blocking)
  227. * this is so we don't block here forever, and can stop this thread when
  228. * the time comes. However, we do need to implement blocking with timeout
  229. * semantics here instead.
  230. */
  231. while (!finished) {
  232. conres = conn_read_result_ex(conn, NULL, NULL, &returned_controls, LDAP_RES_ANY, &message_id, 0);
  233. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "repl5_inc_result_threadmain - "
  234. "Read result for message_id %d\n",
  235. message_id);
  236. /* Timeout here means that we didn't block, not a real timeout */
  237. if (CONN_TIMEOUT == conres) {
  238. /* We need to a) check that the 'real' timeout hasn't expired and
  239. * b) implement a backoff sleep to avoid spinning */
  240. /* Did the connection's timeout expire ? */
  241. time_now = slapi_current_utc_time();
  242. if (conn_get_timeout(conn) <= (time_now - start_time)) {
  243. /* We timed out */
  244. conres = CONN_TIMEOUT;
  245. break;
  246. }
  247. /* Otherwise we backoff */
  248. DS_Sleep(PR_MillisecondsToInterval(backoff_time));
  249. if (backoff_time < 1000) {
  250. backoff_time <<= 1;
  251. }
  252. /* Should we stop ? */
  253. PR_Lock(rd->lock);
  254. if (rd->stop_result_thread) {
  255. finished = 1;
  256. }
  257. PR_Unlock(rd->lock);
  258. } else {
  259. /*
  260. * Something other than a timeout, so we exit the loop.
  261. * First check if we were told to abort the session
  262. */;
  263. Replica *r = (Replica *)object_get_data(rd->prp->replica_object);
  264. if (replica_get_release_timeout(r) &&
  265. slapi_control_present(returned_controls,
  266. REPL_ABORT_SESSION_OID,
  267. NULL, NULL)) {
  268. yield_session = 1;
  269. }
  270. break;
  271. }
  272. }
  273. if (conres != CONN_TIMEOUT) {
  274. int return_value;
  275. int should_finish = 0;
  276. if (message_id) {
  277. rd->last_message_id_received = message_id;
  278. }
  279. /* Handle any error etc */
  280. /* Get the stored operation details from the queue, unless we timed out... */
  281. op = repl5_inc_pop_operation(rd);
  282. if (op) {
  283. csn_str = op->csn_str;
  284. replica_id = op->replica_id;
  285. uniqueid = op->uniqueid;
  286. }
  287. conn_get_error_ex(conn, &operation_code, &connection_error, &ldap_error_string);
  288. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  289. "repl5_inc_result_threadmain - Result %d, %d, %d, %d, %s\n",
  290. operation_code, connection_error, conres, message_id, ldap_error_string);
  291. return_value = repl5_inc_update_from_op_result(rd->prp, conres, connection_error,
  292. csn_str, uniqueid, replica_id, &should_finish,
  293. &(rd->num_changes_sent));
  294. if (return_value || should_finish) {
  295. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  296. "repl5_inc_result_threadmain - Got op result %d should finish %d\n",
  297. return_value, should_finish);
  298. /* If so then we need to take steps to abort the update process */
  299. PR_Lock(rd->lock);
  300. rd->result = return_value;
  301. rd->abort = ABORT_SESSION;
  302. PR_Unlock(rd->lock);
  303. /*
  304. * We also need to log the error, including details stored from
  305. * when the operation was sent. We cannot finish yet - we still
  306. * need to wait for the pending results, then the main repl code
  307. * will shut down this thread. We can finish if we have
  308. * disconnected - in that case, there will be nothing to read
  309. */
  310. if (return_value == UPDATE_CONNECTION_LOST) {
  311. finished = 1;
  312. }
  313. } else {
  314. /* old semantics had result set outside of lock */
  315. rd->result = return_value;
  316. }
  317. }
  318. /* Should we stop ? */
  319. PR_Lock(rd->lock);
  320. if (!finished && yield_session && rd->abort != SESSION_ABORTED && rd->abort_time == 0) {
  321. rd->abort_time = slapi_current_utc_time();
  322. rd->abort = SESSION_ABORTED; /* only set the abort time once */
  323. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "repl5_inc_result_threadmain - "
  324. "Abort control detected, setting abort time...(%s)\n",
  325. agmt_get_long_name(rd->prp->agmt));
  326. }
  327. if (rd->stop_result_thread) {
  328. finished = 1;
  329. }
  330. PR_Unlock(rd->lock);
  331. if (op) {
  332. repl5_inc_op_free(op);
  333. }
  334. }
  335. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "repl5_inc_result_threadmain exiting\n");
  336. }
  337. static result_data *
  338. repl5_inc_rd_new(Private_Repl_Protocol *prp)
  339. {
  340. result_data *res = NULL;
  341. res = (result_data *)slapi_ch_calloc(1, sizeof(result_data));
  342. if (res) {
  343. res->prp = prp;
  344. res->lock = PR_NewLock();
  345. if (NULL == res->lock) {
  346. slapi_ch_free((void **)&res);
  347. res = NULL;
  348. }
  349. }
  350. return res;
  351. }
  352. static void
  353. repl5_inc_rd_list_destroy(repl5_inc_operation *op)
  354. {
  355. while (op) {
  356. repl5_inc_operation *next = op->next;
  357. repl5_inc_op_free(op);
  358. op = next;
  359. }
  360. }
  361. static void
  362. repl5_inc_rd_destroy(result_data **pres)
  363. {
  364. result_data *res = *pres;
  365. if (res->lock) {
  366. PR_DestroyLock(res->lock);
  367. }
  368. /* Delete the linked list if we have one */
  369. /* Begin at the head */
  370. repl5_inc_rd_list_destroy(res->operation_list_head);
  371. slapi_ch_free((void **)pres);
  372. }
  373. static int
  374. repl5_inc_create_async_result_thread(result_data *rd)
  375. {
  376. int retval = 0;
  377. PRThread *tid = NULL;
  378. /* Create a thread that reads results from the connection and stores status in the callback_data structure */
  379. tid = PR_CreateThread(PR_USER_THREAD,
  380. repl5_inc_result_threadmain, (void *)rd,
  381. PR_PRIORITY_NORMAL, PR_GLOBAL_THREAD, PR_JOINABLE_THREAD,
  382. SLAPD_DEFAULT_THREAD_STACKSIZE);
  383. if (NULL == tid) {
  384. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  385. "repl5_inc_create_async_result_thread - Failed. " SLAPI_COMPONENT_NAME_NSPR " error %d (%s)\n",
  386. PR_GetError(), slapd_pr_strerror(PR_GetError()));
  387. retval = -1;
  388. } else {
  389. rd->result_tid = tid;
  390. }
  391. return retval;
  392. }
  393. static int
  394. repl5_inc_destroy_async_result_thread(result_data *rd)
  395. {
  396. int retval = 0;
  397. PRThread *tid = rd->result_tid;
  398. if (tid) {
  399. PR_Lock(rd->lock);
  400. rd->stop_result_thread = 1;
  401. PR_Unlock(rd->lock);
  402. (void)PR_JoinThread(tid);
  403. }
  404. return retval;
  405. }
  406. /* The interest of this routine is to give time to the consumer
  407. * to apply the sent updates and return the acks.
  408. * So the caller should not hold the replication connection lock
  409. * to let the RA.reader receives the acks.
  410. */
  411. static void
  412. repl5_inc_flow_control_results(Repl_Agmt *agmt, result_data *rd)
  413. {
  414. PR_Lock(rd->lock);
  415. if ((rd->last_message_id_received <= rd->last_message_id_sent) &&
  416. ((rd->last_message_id_sent - rd->last_message_id_received) >= agmt_get_flowcontrolwindow(agmt))) {
  417. rd->flowcontrol_detection++;
  418. PR_Unlock(rd->lock);
  419. DS_Sleep(PR_MillisecondsToInterval(agmt_get_flowcontrolpause(agmt)));
  420. } else {
  421. PR_Unlock(rd->lock);
  422. }
  423. }
  424. static int
  425. repl5_inc_waitfor_async_results(result_data *rd)
  426. {
  427. int done = 0;
  428. int loops = 0;
  429. int rc = UPDATE_NO_MORE_UPDATES;
  430. /* Keep pulling results off the LDAP connection until we catch up to the last message id stored in the rd */
  431. while (!done && !slapi_is_shutting_down()) {
  432. /* Lock the structure to force memory barrier */
  433. PR_Lock(rd->lock);
  434. /* Are we caught up ? */
  435. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  436. "repl5_inc_waitfor_async_results - %d %d\n",
  437. rd->last_message_id_received, rd->last_message_id_sent);
  438. if (rd->last_message_id_received >= rd->last_message_id_sent) {
  439. /* If so then we're done */
  440. done = 1;
  441. } else if (rd->abort && (rd->result == UPDATE_CONNECTION_LOST)) {
  442. done = 1; /* no connection == no more results */
  443. }
  444. /*
  445. * Return the last operation result
  446. */
  447. rc = rd->result;
  448. PR_Unlock(rd->lock);
  449. if (!done) {
  450. /* If not then sleep a bit */
  451. DS_Sleep(PR_MillisecondsToInterval(rd->WaitForAsyncResults));
  452. }
  453. loops++;
  454. /* If we sleep forever then we can conclude that something bad happened, and bail... */
  455. /* Arbitrary 30 second delay : basically we should only expect to wait as long as it takes to process a few operations, which should be on the order of a second at most */
  456. if (!done && (loops > 300)) {
  457. /* Log a warning */
  458. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  459. "repl5_inc_waitfor_async_results - Timed out waiting for responses: %d %d\n",
  460. rd->last_message_id_received, rd->last_message_id_sent);
  461. done = 1;
  462. }
  463. }
  464. return rc;
  465. }
  466. /*
  467. * It's specifically ok to delete a protocol instance that
  468. * is currently running. The instance will be shut down, and
  469. * then resources will be freed. Since a graceful shutdown is
  470. * attempted, this function may take some time to complete.
  471. */
  472. static void
  473. repl5_inc_delete(Private_Repl_Protocol **prpp)
  474. {
  475. repl5_inc_private *prp_priv = (repl5_inc_private *)(*prpp)->private;
  476. /* if backoff is set, delete it (from EQ, as well) */
  477. if (prp_priv->backoff) {
  478. backoff_delete(&prp_priv->backoff);
  479. }
  480. /* First, stop the protocol if it isn't already stopped */
  481. if (!(*prpp)->stopped) {
  482. (*prpp)->stopped = 1;
  483. (*prpp)->stop(*prpp);
  484. }
  485. /* Then, delete all resources used by the protocol */
  486. if ((*prpp)->lock) {
  487. PR_DestroyLock((*prpp)->lock);
  488. (*prpp)->lock = NULL;
  489. }
  490. if ((*prpp)->cvar) {
  491. PR_DestroyCondVar((*prpp)->cvar);
  492. (*prpp)->cvar = NULL;
  493. }
  494. slapi_ch_free((void **)&(*prpp)->private);
  495. slapi_ch_free((void **)prpp);
  496. }
  497. /* helper function */
  498. void
  499. set_pause_and_busy_time(Private_Repl_Protocol *prp, long *pausetime, long *busywaittime)
  500. {
  501. /* If neither are set, set busy time to its default */
  502. if (!*pausetime && !*busywaittime) {
  503. *busywaittime = repl5_get_backoff_min(prp);
  504. }
  505. /* pause time must be at least 1 more than the busy backoff time */
  506. if (*pausetime && !*busywaittime) {
  507. /*
  508. * user specified a pause time but no busy wait time - must
  509. * set busy wait time to 1 less than pause time - if pause
  510. * time is 1, we must set it to 2
  511. */
  512. if (*pausetime < 2) {
  513. *pausetime = 2;
  514. }
  515. *busywaittime = *pausetime - 1;
  516. } else if (!*pausetime && *busywaittime) {
  517. /*
  518. * user specified a busy wait time but no pause time - must
  519. * set pause time to 1 more than busy wait time
  520. */
  521. *pausetime = *busywaittime + 1;
  522. } else if (*pausetime && *busywaittime && *pausetime <= *busywaittime) {
  523. /*
  524. * user specified both pause and busy wait times, but the pause
  525. * time was <= busy wait time - pause time must be at least
  526. * 1 more than the busy wait time
  527. */
  528. *pausetime = *busywaittime + 1;
  529. }
  530. }
  531. /*
  532. * Do the incremental protocol.
  533. *
  534. * What's going on here? This thing is a state machine. It has the
  535. * following states:
  536. *
  537. * State transition table:
  538. *
  539. * Curr State Condition/Event Next State
  540. * ---------- ------------ -----------
  541. * START schedule window is open ACQUIRE_REPLICA
  542. * schedule window is closed WAIT_WINDOW_OPEN
  543. * WAIT_WINDOW_OPEN schedule change START
  544. * replicate now ACQUIRE_REPLICA
  545. * schedule window opens ACQUIRE_REPLICA
  546. * ACQUIRE_REPLICA acquired replica SEND_CHANGES
  547. * failed to acquire - transient error START_BACKOFF
  548. * failed to acquire - fatal error STOP_FATAL_ERROR
  549. * SEND_CHANGES can't update CONSUMER_NEEDS_REINIT
  550. * no changes to send WAIT_CHANGES
  551. * can't send - thransient error START_BACKOF
  552. * can't send - window closed WAIT_WINDOW_OPEN
  553. * can'r send - fatal error STOP_FATAL_ERROR
  554. * START_BACKOF replicate now ACQUIRE_REPLICA
  555. * schedule changes START
  556. * schedule window closes WAIT_WINDOW_OPEN
  557. * backoff expires & can acquire SEND_CHANGES
  558. * backoff expires & can't acquire-trans BACKOFF
  559. * backoff expires & can't acquire-fatal STOP_FATAL_ERROR
  560. * BACKOF replicate now ACQUIRE_REPLICA
  561. * schedule changes START
  562. * schedule window closes WAIT_WINDOW_OPEN
  563. * backoff expires & can acquire SEND_CHANGES
  564. * backoff expires & can't acquire-trans BACKOFF
  565. * backoff expires & can't acquire-fatal STOP_FATAL_ERROR
  566. * WAIT_CHANGES schedule window closes WAIT_WINDOW_OPEN
  567. * replicate_now ACQUIRE_REPLICA
  568. * change available ACQUIRE_REPLICA
  569. * schedule_change START
  570. */
  571. /*
  572. * Main state machine for the incremental protocol. This routine will,
  573. * under normal circumstances, not return until the protocol is shut
  574. * down.
  575. */
  576. static void
  577. repl5_inc_run(Private_Repl_Protocol *prp)
  578. {
  579. repl5_inc_private *prp_priv = (repl5_inc_private *)prp->private;
  580. Replica *replica = NULL;
  581. CSN *cons_schema_csn;
  582. RUV *ruv = NULL;
  583. PRUint32 num_changes_sent;
  584. /* use a different backoff timer strategy for ACQUIRE_REPLICA_BUSY errors */
  585. PRBool use_busy_backoff_timer = PR_FALSE;
  586. time_t next_fire_time;
  587. time_t now;
  588. long busywaittime = 0;
  589. long pausetime = 0;
  590. long loops = 0;
  591. int wait_change_timer_set = 0;
  592. int current_state = STATE_START;
  593. int next_state = STATE_START;
  594. int done;
  595. int e1;
  596. prp->stopped = 0;
  597. prp->terminate = 0;
  598. /* establish_protocol_callbacks(prp); */
  599. done = 0;
  600. do {
  601. int rc;
  602. /* Take action, based on current state, and compute new state. */
  603. switch (current_state) {
  604. case STATE_START:
  605. dev_debug("repl5_inc_run(STATE_START)");
  606. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  607. done = 1;
  608. break;
  609. }
  610. /*
  611. * Our initial state. See if we're in a schedule window. If
  612. * so, then we're ready to acquire the replica and see if it
  613. * needs any updates from us. If not, then wait for the window
  614. * to open.
  615. */
  616. if (agmt_schedule_in_window_now(prp->agmt)) {
  617. next_state = STATE_READY_TO_ACQUIRE;
  618. } else {
  619. next_state = STATE_WAIT_WINDOW_OPEN;
  620. }
  621. /* we can get here from other states because some events happened and were
  622. * not cleared. For instance when we wake up in STATE_WAIT_CHANGES state.
  623. * Since this is a fresh start state, we should clear all events */
  624. /* ONREPL - this does not feel right - we should take another look
  625. * at this state machine */
  626. reset_events(prp);
  627. /* Cancel any linger timer that might be in effect... */
  628. conn_cancel_linger(prp->conn);
  629. /* ... and disconnect, if currently connected */
  630. conn_disconnect(prp->conn);
  631. /* get the new pause time, if any */
  632. pausetime = agmt_get_pausetime(prp->agmt);
  633. /* get the new busy wait time, if any */
  634. busywaittime = agmt_get_busywaittime(prp->agmt);
  635. if (pausetime || busywaittime) {
  636. /* helper function to make sure they are set correctly */
  637. set_pause_and_busy_time(prp, &pausetime, &busywaittime);
  638. }
  639. break;
  640. case STATE_WAIT_WINDOW_OPEN:
  641. /*
  642. * We're waiting for a schedule window to open. If one did,
  643. * or we receive a "replicate now" event, then start a protocol
  644. * session immediately. If the replication schedule changed, go
  645. * back to start. Otherwise, go back to sleep.
  646. */
  647. dev_debug("repl5_inc_run(STATE_WAIT_WINDOW_OPEN)");
  648. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  649. done = 1;
  650. break;
  651. } else if (event_occurred(prp, EVENT_WINDOW_OPENED)) {
  652. next_state = STATE_READY_TO_ACQUIRE;
  653. } else if (event_occurred(prp, EVENT_REPLICATE_NOW)) {
  654. next_state = STATE_READY_TO_ACQUIRE;
  655. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)) {
  656. next_state = STATE_START;
  657. conn_set_agmt_changed(prp->conn);
  658. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)) { /* change available */
  659. /* just ignore it and go to sleep */
  660. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  661. } else if ((e1 = event_occurred(prp, EVENT_WINDOW_CLOSED)) ||
  662. event_occurred(prp, EVENT_BACKOFF_EXPIRED)) {
  663. /* this events - should not occur - log a warning and go to sleep */
  664. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  665. "repl5_inc_run - %s: "
  666. "Event %s should not occur in state %s; going to sleep\n",
  667. agmt_get_long_name(prp->agmt), e1 ? event2name(EVENT_WINDOW_CLOSED) : event2name(EVENT_BACKOFF_EXPIRED), state2name(current_state));
  668. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  669. } else {
  670. /* wait until window opens or an event occurs */
  671. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  672. "repl5_inc_run - %s: Waiting for update window to open\n",
  673. agmt_get_long_name(prp->agmt));
  674. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  675. }
  676. break;
  677. case STATE_WAIT_CHANGES:
  678. /*
  679. * We're in a replication window, but we're waiting for more
  680. * changes to accumulate before we actually hook up and send
  681. * them.
  682. */
  683. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES)");
  684. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  685. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): PROTOCOL_IS_SHUTING_DOWN -> end repl5_inc_run\n");
  686. done = 1;
  687. break;
  688. } else if (event_occurred(prp, EVENT_REPLICATE_NOW)) {
  689. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_REPLICATE_NOW received -> STATE_READY_TO_ACQUIRE\n");
  690. next_state = STATE_READY_TO_ACQUIRE;
  691. wait_change_timer_set = 0;
  692. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)) {
  693. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_AGMT_CHANGED received -> STATE_START\n");
  694. next_state = STATE_START;
  695. conn_set_agmt_changed(prp->conn);
  696. wait_change_timer_set = 0;
  697. } else if (event_occurred(prp, EVENT_WINDOW_CLOSED)) {
  698. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_WINDOW_CLOSED received -> STATE_WAIT_WINDOW_OPEN\n");
  699. next_state = STATE_WAIT_WINDOW_OPEN;
  700. wait_change_timer_set = 0;
  701. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)) {
  702. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_TRIGGERING_CRITERIA_MET received -> STATE_READY_TO_ACQUIRE\n");
  703. next_state = STATE_READY_TO_ACQUIRE;
  704. wait_change_timer_set = 0;
  705. } else if ((e1 = event_occurred(prp, EVENT_WINDOW_OPENED)) || event_occurred(prp, EVENT_BACKOFF_EXPIRED)) {
  706. /* this events - should not occur - log a warning and clear the event */
  707. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name, "repl5_inc_run - %s: "
  708. "Event %s should not occur in state %s\n",
  709. agmt_get_long_name(prp->agmt),
  710. e1 ? event2name(EVENT_WINDOW_OPENED) : event2name(EVENT_BACKOFF_EXPIRED),
  711. state2name(current_state));
  712. wait_change_timer_set = 0;
  713. } else {
  714. if (wait_change_timer_set) {
  715. /* We are here because our timer expired */
  716. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): wait_change_timer_set expired -> STATE_START\n");
  717. next_state = STATE_START;
  718. wait_change_timer_set = 0;
  719. } else {
  720. /*
  721. * We are here because the last replication session
  722. * finished or aborted.
  723. */
  724. wait_change_timer_set = 1;
  725. protocol_sleep(prp, MAX_WAIT_BETWEEN_SESSIONS);
  726. }
  727. }
  728. break;
  729. case STATE_READY_TO_ACQUIRE:
  730. dev_debug("repl5_inc_run(STATE_READY_TO_ACQUIRE)");
  731. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  732. done = 1;
  733. break;
  734. }
  735. /* ONREPL - at this state we unconditionally acquire the replica
  736. ignoring all events. Not sure if this is good */
  737. object_acquire(prp->replica_object);
  738. rc = acquire_replica(prp, REPL_NSDS50_INCREMENTAL_PROTOCOL_OID, &ruv);
  739. use_busy_backoff_timer = PR_FALSE; /* default */
  740. if (rc == ACQUIRE_SUCCESS) {
  741. next_state = STATE_SENDING_UPDATES;
  742. } else if (rc == ACQUIRE_REPLICA_BUSY) {
  743. next_state = STATE_BACKOFF_START;
  744. use_busy_backoff_timer = PR_TRUE;
  745. } else if (rc == ACQUIRE_CONSUMER_WAS_UPTODATE) {
  746. next_state = STATE_WAIT_CHANGES;
  747. } else if (rc == ACQUIRE_TRANSIENT_ERROR) {
  748. next_state = STATE_BACKOFF_START;
  749. } else if (rc == ACQUIRE_FATAL_ERROR) {
  750. next_state = STATE_STOP_FATAL_ERROR;
  751. }
  752. object_release(prp->replica_object);
  753. break;
  754. case STATE_BACKOFF_START:
  755. dev_debug("repl5_inc_run(STATE_BACKOFF_START)");
  756. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  757. done = 1;
  758. break;
  759. }
  760. if (event_occurred(prp, EVENT_REPLICATE_NOW)) {
  761. next_state = STATE_READY_TO_ACQUIRE;
  762. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)) {
  763. next_state = STATE_START;
  764. conn_set_agmt_changed(prp->conn);
  765. } else if (event_occurred(prp, EVENT_WINDOW_CLOSED)) {
  766. next_state = STATE_WAIT_WINDOW_OPEN;
  767. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)) {
  768. /* consume and ignore */
  769. } else if ((e1 = event_occurred(prp, EVENT_WINDOW_OPENED)) ||
  770. event_occurred(prp, EVENT_BACKOFF_EXPIRED)) {
  771. /* This should never happen */
  772. /* this events - should not occur - log a warning and go to sleep */
  773. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  774. "repl5_inc_run - %s: Event %s should not occur in state %s\n",
  775. agmt_get_long_name(prp->agmt),
  776. e1 ? event2name(EVENT_WINDOW_OPENED) : event2name(EVENT_BACKOFF_EXPIRED),
  777. state2name(current_state));
  778. } else {
  779. /* Set up the backoff timer to wake us up at the appropriate time */
  780. /* if previous backoff set up, delete it. */
  781. if (prp_priv->backoff) {
  782. backoff_delete(&prp_priv->backoff);
  783. }
  784. if (use_busy_backoff_timer) {
  785. /* we received a busy signal from the consumer, wait for a while */
  786. if (!busywaittime) {
  787. busywaittime = repl5_get_backoff_min(prp);
  788. }
  789. prp_priv->backoff = backoff_new(BACKOFF_FIXED, busywaittime, busywaittime);
  790. } else {
  791. prp_priv->backoff = backoff_new(BACKOFF_EXPONENTIAL, repl5_get_backoff_min(prp),
  792. repl5_get_backoff_max(prp));
  793. }
  794. next_state = STATE_BACKOFF;
  795. backoff_reset(prp_priv->backoff, repl5_inc_backoff_expired, (void *)prp);
  796. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  797. use_busy_backoff_timer = PR_FALSE;
  798. }
  799. break;
  800. case STATE_BACKOFF:
  801. /*
  802. * We're in a backoff state.
  803. */
  804. dev_debug("repl5_inc_run(STATE_BACKOFF)");
  805. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  806. if (prp_priv->backoff)
  807. backoff_delete(&prp_priv->backoff);
  808. done = 1;
  809. break;
  810. } else if (event_occurred(prp, EVENT_REPLICATE_NOW)) {
  811. next_state = STATE_READY_TO_ACQUIRE;
  812. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)) {
  813. next_state = STATE_START;
  814. conn_set_agmt_changed(prp->conn);
  815. /* Destroy the backoff timer, since we won't need it anymore */
  816. if (prp_priv->backoff)
  817. backoff_delete(&prp_priv->backoff);
  818. } else if (event_occurred(prp, EVENT_WINDOW_CLOSED)) {
  819. next_state = STATE_WAIT_WINDOW_OPEN;
  820. /* Destroy the backoff timer, since we won't need it anymore */
  821. if (prp_priv->backoff)
  822. backoff_delete(&prp_priv->backoff);
  823. } else if (event_occurred(prp, EVENT_BACKOFF_EXPIRED)) {
  824. rc = acquire_replica(prp, REPL_NSDS50_INCREMENTAL_PROTOCOL_OID, &ruv);
  825. use_busy_backoff_timer = PR_FALSE;
  826. if (rc == ACQUIRE_SUCCESS) {
  827. next_state = STATE_SENDING_UPDATES;
  828. } else if (rc == ACQUIRE_REPLICA_BUSY) {
  829. next_state = STATE_BACKOFF;
  830. use_busy_backoff_timer = PR_TRUE;
  831. } else if (rc == ACQUIRE_CONSUMER_WAS_UPTODATE) {
  832. next_state = STATE_WAIT_CHANGES;
  833. } else if (rc == ACQUIRE_TRANSIENT_ERROR) {
  834. next_state = STATE_BACKOFF;
  835. } else if (rc == ACQUIRE_FATAL_ERROR) {
  836. next_state = STATE_STOP_FATAL_ERROR;
  837. }
  838. /*
  839. * We either need to step the backoff timer, or
  840. * destroy it if we don't need it anymore
  841. */
  842. if (STATE_BACKOFF == next_state) {
  843. /* Step the backoff timer */
  844. now = slapi_current_utc_time();
  845. next_fire_time = backoff_step(prp_priv->backoff);
  846. /* And go back to sleep */
  847. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  848. "repl5_inc_run - %s: Replication session backing off for %ld seconds\n",
  849. agmt_get_long_name(prp->agmt), next_fire_time - now);
  850. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  851. } else {
  852. /* Destroy the backoff timer, since we won't need it anymore */
  853. backoff_delete(&prp_priv->backoff);
  854. }
  855. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)) {
  856. /* changes are available */
  857. if (prp_priv->backoff == NULL || backoff_expired(prp_priv->backoff, 60)) {
  858. /*
  859. * Have seen cases that the agmt stuck here forever since
  860. * somehow the backoff timer was not in event queue anymore.
  861. * If the backoff timer has expired more than 60 seconds, destroy it.
  862. */
  863. if (prp_priv->backoff)
  864. backoff_delete(&prp_priv->backoff);
  865. next_state = STATE_READY_TO_ACQUIRE;
  866. } else {
  867. /* ignore changes and go to sleep */
  868. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  869. }
  870. } else if (event_occurred(prp, EVENT_WINDOW_OPENED)) {
  871. /* this should never happen - log an error and go to sleep */
  872. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name, "repl5_inc_run - %s: "
  873. "Event %s should not occur in state %s; going to sleep\n",
  874. agmt_get_long_name(prp->agmt), event2name(EVENT_WINDOW_OPENED),
  875. state2name(current_state));
  876. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  877. }
  878. break;
  879. case STATE_SENDING_UPDATES:
  880. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES)");
  881. num_changes_sent = 0;
  882. /*
  883. * We've acquired the replica, and are ready to send any needed updates.
  884. */
  885. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  886. release_replica(prp);
  887. done = 1;
  888. agmt_set_update_in_progress(prp->agmt, PR_FALSE);
  889. agmt_set_last_update_end(prp->agmt, slapi_current_utc_time());
  890. /* MAB: I don't find the following status correct. How do we know it has
  891. * been stopped by an admin and not by a total update request, for instance?
  892. * In any case, how is this protocol shutdown situation different from all the
  893. * other ones that are present in this state machine? */
  894. /* richm: We at least need to let monitors know that the protocol has been
  895. * shutdown - maybe they can figure out why */
  896. agmt_set_last_update_status(prp->agmt, 0, 0, "Protocol stopped");
  897. agmt_update_done(prp->agmt, 0);
  898. break;
  899. }
  900. agmt_set_last_update_status(prp->agmt, 0, 0, "Incremental update started");
  901. /* ONREPL - in this state we send changes no matter what other events occur.
  902. * This is because we can get because of the REPLICATE_NOW event which
  903. * has high priority. Is this ok? */
  904. /* First, push new schema to the consumer if needed */
  905. /* ONREPL - should we push schema after we examine the RUV? */
  906. /*
  907. * GGOOREPL - I don't see why we should wait until we've
  908. * examined the RUV. The schema entry has its own CSN that is
  909. * used to decide if the remote schema needs to be updated.
  910. */
  911. cons_schema_csn = agmt_get_consumer_schema_csn(prp->agmt);
  912. rc = conn_push_schema(prp->conn, &cons_schema_csn);
  913. if (cons_schema_csn != agmt_get_consumer_schema_csn(prp->agmt)) {
  914. agmt_set_consumer_schema_csn(prp->agmt, cons_schema_csn);
  915. }
  916. if (CONN_SCHEMA_UPDATED != rc && CONN_SCHEMA_NO_UPDATE_NEEDED != rc) {
  917. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  918. "%s: Warning: unable to replicate schema: rc=%d\n", agmt_get_long_name(prp->agmt), rc);
  919. /* But keep going */
  920. }
  921. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> examine_update_vector");
  922. rc = examine_update_vector(prp, ruv);
  923. /*
  924. * Decide what to do next - proceed with incremental, backoff, or total update
  925. */
  926. switch (rc) {
  927. case EXAMINE_RUV_PARAM_ERROR:
  928. /* this is really bad - we have NULL prp! */
  929. next_state = STATE_STOP_FATAL_ERROR;
  930. break;
  931. case EXAMINE_RUV_PRISTINE_REPLICA:
  932. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  933. "repl5_inc_run - %s: Replica has no update vector. It has never been initialized.\n",
  934. agmt_get_long_name(prp->agmt));
  935. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_RUV_ERROR,
  936. "Replica is not initialized");
  937. next_state = STATE_BACKOFF_START;
  938. break;
  939. case EXAMINE_RUV_GENERATION_MISMATCH:
  940. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  941. "repl5_inc_run - %s: The remote replica has a different database generation ID than "
  942. "the local database. You may have to reinitialize the remote replica, "
  943. "or the local replica.\n",
  944. agmt_get_long_name(prp->agmt));
  945. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_RUV_ERROR,
  946. "Replica has different database generation ID, remote "
  947. "replica may need to be initialized");
  948. next_state = STATE_BACKOFF_START;
  949. break;
  950. case EXAMINE_RUV_REPLICA_TOO_OLD:
  951. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  952. "repl5_inc_run - %s: Replica update vector is too out of date to bring "
  953. "into sync using the incremental protocol. The replica "
  954. "must be reinitialized.\n",
  955. agmt_get_long_name(prp->agmt));
  956. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_RUV_ERROR,
  957. "Replica needs to be reinitialized");
  958. next_state = STATE_BACKOFF_START;
  959. break;
  960. case EXAMINE_RUV_OK:
  961. /* update our csn generator state with the consumer's ruv data */
  962. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> examine_update_vector OK");
  963. object_acquire(prp->replica_object);
  964. replica = object_get_data(prp->replica_object);
  965. rc = replica_update_csngen_state(replica, ruv);
  966. object_release(prp->replica_object);
  967. replica = NULL;
  968. if (rc == CSN_LIMIT_EXCEEDED) /* too much skew */ {
  969. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  970. "repl5_inc_run - %s: Fatal error - too much time skew between replicas!\n",
  971. agmt_get_long_name(prp->agmt));
  972. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_EXCESSIVE_CLOCK_SKEW,
  973. "fatal error - too much time skew between replicas");
  974. next_state = STATE_STOP_FATAL_ERROR;
  975. } else if (rc != 0) /* internal error */ {
  976. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  977. "repl5_inc_run - %s: Fatal internal error updating the CSN generator!\n",
  978. agmt_get_long_name(prp->agmt));
  979. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_INTERNAL_ERROR,
  980. "fatal internal error updating the CSN generator");
  981. next_state = STATE_STOP_FATAL_ERROR;
  982. } else {
  983. /*
  984. * Reset our update times and status
  985. */
  986. agmt_set_last_update_start(prp->agmt, slapi_current_utc_time());
  987. agmt_set_last_update_end(prp->agmt, 0);
  988. agmt_set_update_in_progress(prp->agmt, PR_TRUE);
  989. /*
  990. * Send the updates
  991. */
  992. rc = send_updates(prp, ruv, &num_changes_sent);
  993. if (rc == UPDATE_NO_MORE_UPDATES) {
  994. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_NO_MORE_UPDATES -> STATE_WAIT_CHANGES");
  995. agmt_set_last_update_status(prp->agmt, 0, 0, "Incremental update succeeded");
  996. next_state = STATE_WAIT_CHANGES;
  997. } else if (rc == UPDATE_YIELD) {
  998. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_YIELD -> STATE_BACKOFF_START");
  999. agmt_set_last_update_status(prp->agmt, 0, 0, "Incremental update succeeded and yielded");
  1000. use_busy_backoff_timer = PR_TRUE;
  1001. next_state = STATE_BACKOFF_START;
  1002. } else if (rc == UPDATE_TRANSIENT_ERROR) {
  1003. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_TRANSIENT_ERROR -> STATE_BACKOFF_START");
  1004. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_TRANSIENT_ERROR,
  1005. "Incremental update transient error. Backing off, will retry update later.");
  1006. next_state = STATE_BACKOFF_START;
  1007. } else if (rc == UPDATE_FATAL_ERROR) {
  1008. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_FATAL_ERROR -> STATE_STOP_FATAL_ERROR");
  1009. next_state = STATE_STOP_FATAL_ERROR;
  1010. } else if (rc == UPDATE_SCHEDULE_WINDOW_CLOSED) {
  1011. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_SCHEDULE_WINDOW_CLOSED -> STATE_WAIT_WINDOW_OPEN");
  1012. /*
  1013. * ONREPL - I don't think we should check this. We might be
  1014. * here because of replicate_now event - so we don't care
  1015. * about the schedule
  1016. */
  1017. next_state = STATE_WAIT_WINDOW_OPEN;
  1018. /* ONREPL - do we need to release the replica here ? */
  1019. conn_disconnect(prp->conn);
  1020. } else if (rc == UPDATE_CONNECTION_LOST) {
  1021. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_CONNECTION_LOST -> STATE_BACKOFF_START");
  1022. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CONN_ERROR,
  1023. "Incremental update connection error. Backing off, will retry update later.");
  1024. next_state = STATE_BACKOFF_START;
  1025. } else if (rc == UPDATE_TIMEOUT) {
  1026. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_TIMEOUT -> STATE_BACKOFF_START");
  1027. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CONN_TIMEOUT,
  1028. "Incremental update timeout error. Backing off, will retry update later.");
  1029. next_state = STATE_BACKOFF_START;
  1030. }
  1031. /* Set the updates times based off the result of send_updates() */
  1032. if (rc == UPDATE_NO_MORE_UPDATES) {
  1033. /* update successful, set the end time */
  1034. agmt_set_last_update_end(prp->agmt, slapi_current_utc_time());
  1035. } else {
  1036. /* Failed to send updates, reset the start time to zero */
  1037. agmt_set_last_update_start(prp->agmt, 0);
  1038. }
  1039. agmt_set_update_in_progress(prp->agmt, PR_FALSE);
  1040. }
  1041. break;
  1042. }
  1043. if (NULL != ruv) {
  1044. ruv_destroy(&ruv);
  1045. ruv = NULL;
  1046. }
  1047. agmt_update_done(prp->agmt, 0);
  1048. /* If timed out, close the connection after released the replica */
  1049. release_replica(prp);
  1050. if (rc == UPDATE_TIMEOUT) {
  1051. conn_disconnect(prp->conn);
  1052. }
  1053. if (rc == UPDATE_NO_MORE_UPDATES && num_changes_sent > 0) {
  1054. if (pausetime > 0) {
  1055. /* richm - 20020219 - If we have acquired the consumer, and another master has gone
  1056. * into backoff waiting for us to release it, we may acquire the replica sooner
  1057. * than the other master has a chance to, and the other master may not be able
  1058. * to acquire the consumer for a long time (hours, days?) if this server is
  1059. * under a heavy load (see reliab06 et. al. system tests)
  1060. * So, this sleep gives the other master(s) a chance to acquire the consumer replica */
  1061. loops = pausetime;
  1062. /* the while loop is so that we don't just sleep and sleep if an
  1063. * event comes in that we should handle immediately (like shutdown) */
  1064. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1065. "repl5_inc_run - %s: Pausing updates for %ld seconds to allow other suppliers to update consumer\n",
  1066. agmt_get_long_name(prp->agmt), pausetime);
  1067. while (loops-- && !(PROTOCOL_IS_SHUTDOWN(prp))) {
  1068. DS_Sleep(PR_SecondsToInterval(1));
  1069. }
  1070. } else if (num_changes_sent > 10) {
  1071. /* wait for consumer to write its ruv if the replication was busy */
  1072. /* When asked, consumer sends its ruv in cache to the supplier. */
  1073. /* DS_Sleep ( PR_SecondsToInterval(1) ); */
  1074. }
  1075. }
  1076. break;
  1077. case STATE_STOP_FATAL_ERROR:
  1078. /*
  1079. * We encountered some sort of a fatal error. Suspend.
  1080. */
  1081. dev_debug("repl5_inc_run(STATE_STOP_FATAL_ERROR)");
  1082. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1083. "repl5_inc_run - %s: Incremental update failed and requires administrator action\n",
  1084. agmt_get_long_name(prp->agmt));
  1085. next_state = STATE_STOP_FATAL_ERROR_PART2;
  1086. break;
  1087. case STATE_STOP_FATAL_ERROR_PART2:
  1088. if (PROTOCOL_IS_SHUTDOWN(prp)) {
  1089. done = 1;
  1090. break;
  1091. }
  1092. /* MAB: This state is the FATAL state where we are supposed to get
  1093. * as a result of a FATAL error on send_updates. But, as bug
  1094. * states, send_updates was always returning TRANSIENT errors and never
  1095. * FATAL... In other words, this code has never been tested before...
  1096. *
  1097. * As of 01/16/01, this piece of code was in a very dangerous state. In particular,
  1098. * 1) it does not catch any events
  1099. * 2) it is a terminal state (once reached it never transitions to a different state)
  1100. *
  1101. * Both things combined make this state to become a consuming infinite loop
  1102. * that is useless after all (we are in a fatal place requiring manual admin jobs */
  1103. /* MAB: The following lines fix problem number 1 above... When the code gets
  1104. * into this state, it should only get a chance to get out of it by an
  1105. * EVENT_AGMT_CHANGED event... All other events should be ignored */
  1106. else if (event_occurred(prp, EVENT_AGMT_CHANGED)) {
  1107. dev_debug("repl5_inc_run(STATE_STOP_FATAL_ERROR): EVENT_AGMT_CHANGED received\n");
  1108. /* Chance to recover for the EVENT_AGMT_CHANGED event.
  1109. * This is not mandatory, but fixes problem 2 above */
  1110. next_state = STATE_STOP_NORMAL_TERMINATION;
  1111. } else {
  1112. dev_debug("repl5_inc_run(STATE_STOP_FATAL_ERROR): Event received. Clearing it\n");
  1113. reset_events(prp);
  1114. }
  1115. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  1116. break;
  1117. case STATE_STOP_NORMAL_TERMINATION:
  1118. /*
  1119. * We encountered some sort of a fatal error. Return.
  1120. */
  1121. /* XXXggood update state in replica */
  1122. dev_debug("repl5_inc_run(STATE_STOP_NORMAL_TERMINATION)");
  1123. done = 1;
  1124. break;
  1125. }
  1126. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name, "repl5_inc_run - %s: State: %s -> %s\n",
  1127. agmt_get_long_name(prp->agmt), state2name(current_state), state2name(next_state));
  1128. current_state = next_state;
  1129. } while (!done);
  1130. /* remove_protocol_callbacks(prp); */
  1131. prp->stopped = 1;
  1132. /* Cancel any linger timer that might be in effect... */
  1133. conn_cancel_linger(prp->conn);
  1134. /* ... and disconnect, if currently connected */
  1135. conn_disconnect(prp->conn);
  1136. }
  1137. /*
  1138. * Go to sleep until awakened.
  1139. */
  1140. static void
  1141. protocol_sleep(Private_Repl_Protocol *prp, PRIntervalTime duration)
  1142. {
  1143. PR_ASSERT(NULL != prp);
  1144. PR_Lock(prp->lock);
  1145. /* we should not go to sleep if there are events available to be processed.
  1146. Otherwise, we can miss the event that suppose to wake us up */
  1147. if (prp->eventbits == 0)
  1148. PR_WaitCondVar(prp->cvar, duration);
  1149. else {
  1150. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1151. "protocol_sleep - %s: Can't go to sleep: event bits - %x\n",
  1152. agmt_get_long_name(prp->agmt), prp->eventbits);
  1153. }
  1154. PR_Unlock(prp->lock);
  1155. }
  1156. /*
  1157. * Notify the protocol about some event. Signal the condition
  1158. * variable in case the protocol is sleeping. Multiple occurences
  1159. * of a single event type are not remembered (e.g. no stack
  1160. * of events is maintained).
  1161. */
  1162. static void
  1163. event_notify(Private_Repl_Protocol *prp, PRUint32 event)
  1164. {
  1165. PR_ASSERT(NULL != prp);
  1166. PR_Lock(prp->lock);
  1167. prp->eventbits |= event;
  1168. PR_NotifyCondVar(prp->cvar);
  1169. PR_Unlock(prp->lock);
  1170. }
  1171. /*
  1172. * Test to see if an event occurred. The event is cleared when
  1173. * read.
  1174. */
  1175. static PRUint32
  1176. event_occurred(Private_Repl_Protocol *prp, PRUint32 event)
  1177. {
  1178. PRUint32 return_value;
  1179. PR_ASSERT(NULL != prp);
  1180. PR_Lock(prp->lock);
  1181. return_value = (prp->eventbits & event);
  1182. prp->eventbits &= ~event; /* Clear event */
  1183. PR_Unlock(prp->lock);
  1184. return return_value;
  1185. }
  1186. static void
  1187. reset_events(Private_Repl_Protocol *prp)
  1188. {
  1189. PR_ASSERT(NULL != prp);
  1190. PR_Lock(prp->lock);
  1191. prp->eventbits = 0;
  1192. PR_Unlock(prp->lock);
  1193. }
  1194. /*
  1195. * Replay the actual update to the consumer. Construct an appropriate LDAP
  1196. * operation, attach the baggage LDAPv3 control that contains the CSN, etc.,
  1197. * and send the operation to the consumer.
  1198. */
  1199. ConnResult
  1200. replay_update(Private_Repl_Protocol *prp, slapi_operation_parameters *op, int *message_id)
  1201. {
  1202. ConnResult return_value = CONN_OPERATION_FAILED;
  1203. LDAPControl *update_control;
  1204. char *parentuniqueid;
  1205. LDAPMod **modrdn_mods = NULL;
  1206. char csn_str[CSN_STRSIZE]; /* For logging only */
  1207. if (message_id) {
  1208. /* if we get out of this function without setting message_id, it means
  1209. we didn't send an op, so no result needs to be processed */
  1210. *message_id = 0;
  1211. }
  1212. /* Construct the replication info control that accompanies the operation */
  1213. if (SLAPI_OPERATION_ADD == op->operation_type) {
  1214. parentuniqueid = op->p.p_add.parentuniqueid;
  1215. } else if (SLAPI_OPERATION_MODRDN == op->operation_type) {
  1216. /*
  1217. * For modrdn operations, we need to send along modified attributes, e.g.
  1218. * modifytimestamp.
  1219. * And the superior_uniqueid !
  1220. */
  1221. modrdn_mods = op->p.p_modrdn.modrdn_mods;
  1222. parentuniqueid = op->p.p_modrdn.modrdn_newsuperior_address.uniqueid;
  1223. } else {
  1224. parentuniqueid = NULL;
  1225. }
  1226. if (create_NSDS50ReplUpdateInfoControl(op->target_address.uniqueid,
  1227. parentuniqueid, op->csn, modrdn_mods, &update_control) != LDAP_SUCCESS) {
  1228. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1229. "replay_update - %s: Unable to create NSDS50ReplUpdateInfoControl "
  1230. "for operation with csn %s. Skipping update.\n",
  1231. agmt_get_long_name(prp->agmt), csn_as_string(op->csn, PR_FALSE, csn_str));
  1232. } else {
  1233. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1234. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1235. "replay_update - %s: Sending %s operation (dn=\"%s\" csn=%s)\n",
  1236. agmt_get_long_name(prp->agmt),
  1237. op2string(op->operation_type), REPL_GET_DN(&op->target_address),
  1238. csn_as_string(op->csn, PR_FALSE, csn_str));
  1239. }
  1240. /* What type of operation is it? */
  1241. switch (op->operation_type) {
  1242. case SLAPI_OPERATION_ADD: {
  1243. LDAPMod **entryattrs;
  1244. /* Convert entry to mods */
  1245. (void)slapi_entry2mods(op->p.p_add.target_entry,
  1246. NULL /* &entrydn : We don't need it */,
  1247. &entryattrs);
  1248. if (NULL == entryattrs) {
  1249. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1250. "replay_update - %s: Cannot convert entry to LDAPMods.\n",
  1251. agmt_get_long_name(prp->agmt));
  1252. return_value = CONN_LOCAL_ERROR;
  1253. } else {
  1254. /* If fractional agreement, trim down the entry */
  1255. if (agmt_is_fractional(prp->agmt)) {
  1256. repl5_strip_fractional_mods(prp->agmt, entryattrs);
  1257. }
  1258. if (MODS_ARE_EMPTY(entryattrs)) {
  1259. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1260. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1261. "replay_update - %s: %s operation (dn=\"%s\" csn=%s) "
  1262. "not sent - empty\n",
  1263. agmt_get_long_name(prp->agmt),
  1264. op2string(op->operation_type),
  1265. REPL_GET_DN(&op->target_address),
  1266. csn_as_string(op->csn, PR_FALSE, csn_str));
  1267. }
  1268. return_value = CONN_OPERATION_SUCCESS;
  1269. } else {
  1270. return_value = conn_send_add(prp->conn, REPL_GET_DN(&op->target_address),
  1271. entryattrs, update_control, message_id);
  1272. }
  1273. ldap_mods_free(entryattrs, 1);
  1274. }
  1275. break;
  1276. }
  1277. case SLAPI_OPERATION_MODIFY:
  1278. /* If fractional agreement, trim down the mods */
  1279. if (agmt_is_fractional(prp->agmt)) {
  1280. repl5_strip_fractional_mods(prp->agmt, op->p.p_modify.modify_mods);
  1281. }
  1282. if (MODS_ARE_EMPTY(op->p.p_modify.modify_mods)) {
  1283. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1284. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1285. "replay_update - %s: %s operation (dn=\"%s\" csn=%s) "
  1286. "not sent - empty\n",
  1287. agmt_get_long_name(prp->agmt),
  1288. op2string(op->operation_type),
  1289. REPL_GET_DN(&op->target_address),
  1290. csn_as_string(op->csn, PR_FALSE, csn_str));
  1291. }
  1292. return_value = CONN_OPERATION_SUCCESS;
  1293. } else {
  1294. return_value = conn_send_modify(prp->conn, REPL_GET_DN(&op->target_address),
  1295. op->p.p_modify.modify_mods, update_control, message_id);
  1296. }
  1297. break;
  1298. case SLAPI_OPERATION_DELETE:
  1299. return_value = conn_send_delete(prp->conn, REPL_GET_DN(&op->target_address),
  1300. update_control, message_id);
  1301. break;
  1302. case SLAPI_OPERATION_MODRDN:
  1303. /* XXXggood need to pass modrdn mods in update control! */
  1304. return_value = conn_send_rename(prp->conn, REPL_GET_DN(&op->target_address),
  1305. op->p.p_modrdn.modrdn_newrdn,
  1306. REPL_GET_DN(&op->p.p_modrdn.modrdn_newsuperior_address),
  1307. op->p.p_modrdn.modrdn_deloldrdn,
  1308. update_control, message_id);
  1309. break;
  1310. default:
  1311. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name, "replay_update - %s: Unknown "
  1312. "operation type %lu found in changelog - skipping change.\n",
  1313. agmt_get_long_name(prp->agmt), op->operation_type);
  1314. }
  1315. destroy_NSDS50ReplUpdateInfoControl(&update_control);
  1316. }
  1317. if (CONN_OPERATION_SUCCESS == return_value) {
  1318. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1319. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1320. "replay_update - %s: Consumer successfully sent operation with csn %s\n",
  1321. agmt_get_long_name(prp->agmt), csn_as_string(op->csn, PR_FALSE, csn_str));
  1322. }
  1323. } else {
  1324. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1325. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1326. "replay_update - %s: Consumer could not replay operation with csn %s\n",
  1327. agmt_get_long_name(prp->agmt), csn_as_string(op->csn, PR_FALSE, csn_str));
  1328. }
  1329. }
  1330. return return_value;
  1331. }
  1332. static PRBool
  1333. is_dummy_operation(const slapi_operation_parameters *op)
  1334. {
  1335. return (strcmp(op->target_address.uniqueid, START_ITERATION_ENTRY_UNIQUEID) == 0);
  1336. }
  1337. void
  1338. cl5_operation_parameters_done(struct slapi_operation_parameters *sop)
  1339. {
  1340. if (sop != NULL) {
  1341. switch (sop->operation_type) {
  1342. case SLAPI_OPERATION_BIND:
  1343. slapi_ch_free((void **)&(sop->p.p_bind.bind_saslmechanism));
  1344. if (sop->p.p_bind.bind_creds)
  1345. ber_bvecfree((struct berval **)&(sop->p.p_bind.bind_creds));
  1346. if (sop->p.p_bind.bind_ret_saslcreds)
  1347. ber_bvecfree((struct berval **)&(sop->p.p_bind.bind_ret_saslcreds));
  1348. sop->p.p_bind.bind_creds = NULL;
  1349. sop->p.p_bind.bind_ret_saslcreds = NULL;
  1350. break;
  1351. case SLAPI_OPERATION_COMPARE:
  1352. ava_done((struct ava *)&(sop->p.p_compare.compare_ava));
  1353. break;
  1354. case SLAPI_OPERATION_SEARCH:
  1355. slapi_ch_free((void **)&(sop->p.p_search.search_strfilter));
  1356. charray_free(sop->p.p_search.search_attrs);
  1357. slapi_filter_free(sop->p.p_search.search_filter, 1);
  1358. break;
  1359. case SLAPI_OPERATION_MODRDN:
  1360. sop->p.p_modrdn.modrdn_deloldrdn = 0;
  1361. break;
  1362. case SLAPI_OPERATION_EXTENDED:
  1363. slapi_ch_free((void **)&(sop->p.p_extended.exop_oid));
  1364. if (sop->p.p_extended.exop_value)
  1365. ber_bvecfree((struct berval **)&(sop->p.p_extended.exop_value));
  1366. sop->p.p_extended.exop_value = NULL;
  1367. break;
  1368. default:
  1369. break;
  1370. }
  1371. }
  1372. operation_parameters_done(sop);
  1373. }
  1374. /* Helper to update the agreement state based on a the result of a replay operation */
  1375. static int
  1376. repl5_inc_update_from_op_result(Private_Repl_Protocol *prp, ConnResult replay_crc, int connection_error, char *csn_str, char *uniqueid, ReplicaId replica_id, int *finished, PRUint32 *num_changes_sent)
  1377. {
  1378. int return_value = 0;
  1379. if (CONN_OPERATION_SUCCESS != replay_crc) {
  1380. /* Figure out what to do next */
  1381. if (CONN_OPERATION_FAILED == replay_crc) {
  1382. /* Map ldap error code to return value */
  1383. if (!ignore_error_and_keep_going(connection_error)) {
  1384. return_value = UPDATE_TRANSIENT_ERROR;
  1385. *finished = 1;
  1386. } else {
  1387. agmt_inc_last_update_changecount(prp->agmt, replica_id, 1 /*skipped*/);
  1388. }
  1389. slapi_log_err(*finished ? SLAPI_LOG_WARNING : slapi_log_urp,
  1390. repl_plugin_name,
  1391. "repl5_inc_update_from_op_result - %s: Consumer failed to replay change (uniqueid %s, CSN %s): %s (%d). %s.\n",
  1392. agmt_get_long_name(prp->agmt),
  1393. uniqueid, csn_str,
  1394. ldap_err2string(connection_error), connection_error,
  1395. *finished ? "Will retry later" : "Skipping");
  1396. } else if (CONN_NOT_CONNECTED == replay_crc) {
  1397. /* We lost the connection - enter backoff state */
  1398. return_value = UPDATE_CONNECTION_LOST;
  1399. *finished = 1;
  1400. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1401. "repl5_inc_update_from_op_result - %s: Consumer failed to replay change (uniqueid %s, CSN %s): "
  1402. "%s(%d). Will retry later.\n",
  1403. agmt_get_long_name(prp->agmt),
  1404. uniqueid, csn_str,
  1405. connection_error ? ldap_err2string(connection_error) : "Connection lost",
  1406. connection_error);
  1407. } else if (CONN_TIMEOUT == replay_crc) {
  1408. return_value = UPDATE_TIMEOUT;
  1409. *finished = 1;
  1410. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1411. "repl5_inc_update_from_op_result - %s: Consumer timed out to replay change (uniqueid %s, CSN %s): "
  1412. "%s.\n",
  1413. agmt_get_long_name(prp->agmt),
  1414. uniqueid, csn_str,
  1415. connection_error ? ldap_err2string(connection_error) : "Timeout");
  1416. } else if (CONN_LOCAL_ERROR == replay_crc) {
  1417. /*
  1418. * Something bad happened on the local server - enter
  1419. * backoff state.
  1420. */
  1421. return_value = UPDATE_TRANSIENT_ERROR;
  1422. *finished = 1;
  1423. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1424. "repl5_inc_update_from_op_result - %s: Failed to replay change (uniqueid %s, CSN %s): "
  1425. "Local error. Will retry later.\n",
  1426. agmt_get_long_name(prp->agmt),
  1427. uniqueid, csn_str);
  1428. }
  1429. if (*finished) {
  1430. /*
  1431. * A serious error has occurred, the consumer might have closed
  1432. * the connection already, but we need to close the conn on the
  1433. * supplier side to properly set the conn structure as closed.
  1434. */
  1435. conn_disconnect(prp->conn);
  1436. }
  1437. } else {
  1438. /* Positive response received */
  1439. (*num_changes_sent)++;
  1440. agmt_inc_last_update_changecount(prp->agmt, replica_id, 0 /*replayed*/);
  1441. }
  1442. return return_value;
  1443. }
  1444. /*
  1445. * Send a set of updates to the replica. Assumes that (1) the replica
  1446. * has already been acquired, (2) that the consumer's update vector has
  1447. * been checked and (3) that it's ok to send incremental updates.
  1448. * Returns:
  1449. * UPDATE_NO_MORE_UPDATES - all updates were sent successfully
  1450. * UPDATE_TRANSIENT_ERROR - some non-permanent error occurred. Try again later.
  1451. * UPDATE_FATAL_ERROR - some bad, permanent error occurred.
  1452. * UPDATE_SCHEDULE_WINDOW_CLOSED - the schedule window closed on us.
  1453. */
  1454. static int
  1455. send_updates(Private_Repl_Protocol *prp, RUV *remote_update_vector, PRUint32 *num_changes_sent)
  1456. {
  1457. CL5Entry entry;
  1458. slapi_operation_parameters op;
  1459. int return_value = 0;
  1460. int rc;
  1461. CL5ReplayIterator *changelog_iterator;
  1462. int message_id = 0;
  1463. result_data *rd = NULL;
  1464. *num_changes_sent = 0;
  1465. /*
  1466. * Iterate over the changelog. Retrieve each update,
  1467. * construct an appropriate LDAP operation,
  1468. * attaching the CSN, and send the change.
  1469. */
  1470. rc = cl5CreateReplayIterator(prp, remote_update_vector, &changelog_iterator);
  1471. if (CL5_SUCCESS != rc) {
  1472. switch (rc) {
  1473. case CL5_BAD_DATA: /* invalid parameter passed to the function */
  1474. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1475. "send_updates - %s: Invalid parameter passed to cl5CreateReplayIterator\n",
  1476. agmt_get_long_name(prp->agmt));
  1477. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1478. "Invalid parameter passed to cl5CreateReplayIterator");
  1479. return_value = UPDATE_FATAL_ERROR;
  1480. break;
  1481. case CL5_BAD_FORMAT: /* db data has unexpected format */
  1482. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1483. "send_updates - %s: Unexpected format encountered in changelog database\n",
  1484. agmt_get_long_name(prp->agmt));
  1485. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1486. "Unexpected format encountered in changelog database");
  1487. return_value = UPDATE_FATAL_ERROR;
  1488. break;
  1489. case CL5_BAD_STATE: /* changelog is in an incorrect state for attempted operation */
  1490. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1491. "send_updates - %s: Changelog database was in an incorrect state\n",
  1492. agmt_get_long_name(prp->agmt));
  1493. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1494. "Changelog database was in an incorrect state");
  1495. return_value = UPDATE_FATAL_ERROR;
  1496. break;
  1497. case CL5_BAD_DBVERSION: /* changelog has invalid dbversion */
  1498. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1499. "send_updates - %s: Incorrect dbversion found in changelog database\n",
  1500. agmt_get_long_name(prp->agmt));
  1501. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1502. "Incorrect dbversion found in changelog database");
  1503. return_value = UPDATE_FATAL_ERROR;
  1504. break;
  1505. case CL5_DB_ERROR: /* database error */
  1506. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1507. "send_updates - %s: A changelog database error was encountered\n",
  1508. agmt_get_long_name(prp->agmt));
  1509. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1510. "Changelog database error was encountered");
  1511. return_value = UPDATE_FATAL_ERROR;
  1512. break;
  1513. case CL5_NOTFOUND: /* we have no changes to send */
  1514. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1515. "send_updates - %s: No changes to send\n",
  1516. agmt_get_long_name(prp->agmt));
  1517. return_value = UPDATE_NO_MORE_UPDATES;
  1518. break;
  1519. case CL5_MEMORY_ERROR: /* memory allocation failed */
  1520. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1521. "send_updates - %s: Memory allocation error occurred\n",
  1522. agmt_get_long_name(prp->agmt));
  1523. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1524. "changelog memory allocation error occurred");
  1525. return_value = UPDATE_FATAL_ERROR;
  1526. break;
  1527. case CL5_SYSTEM_ERROR: /* NSPR error occurred: use PR_GetError for further info */
  1528. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1529. "send_updates - %s: An NSPR error (%d) occurred\n",
  1530. agmt_get_long_name(prp->agmt), PR_GetError());
  1531. return_value = UPDATE_TRANSIENT_ERROR;
  1532. break;
  1533. case CL5_CSN_ERROR: /* CSN API failed */
  1534. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1535. "send_updates - %s: A CSN API failure was encountered\n",
  1536. agmt_get_long_name(prp->agmt));
  1537. return_value = UPDATE_TRANSIENT_ERROR;
  1538. break;
  1539. case CL5_RUV_ERROR: /* RUV API failed */
  1540. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1541. "send_updates - %s: An RUV API failure occurred\n",
  1542. agmt_get_long_name(prp->agmt));
  1543. return_value = UPDATE_TRANSIENT_ERROR;
  1544. break;
  1545. case CL5_OBJSET_ERROR: /* namedobjset api failed */
  1546. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1547. "send_updates - %s: A namedobject API failure occurred\n",
  1548. agmt_get_long_name(prp->agmt));
  1549. return_value = UPDATE_TRANSIENT_ERROR;
  1550. break;
  1551. case CL5_PURGED_DATA: /* requested data has been purged */
  1552. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1553. "send_updates - %s: Data required to update replica has been purged from the changelog. "
  1554. "If the error persists the replica must be reinitialized.\n",
  1555. agmt_get_long_name(prp->agmt));
  1556. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1557. "Data required to update replica has been purged from the changelog. "
  1558. "If the error persists the replica must be reinitialized.");
  1559. return_value = UPDATE_TRANSIENT_ERROR;
  1560. break;
  1561. case CL5_MISSING_DATA: /* data should be in the changelog, but is missing */
  1562. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1563. "send_updates - %s: Missing data encountered. "
  1564. "If the error persists the replica must be reinitialized.\n",
  1565. agmt_get_long_name(prp->agmt));
  1566. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1567. "Changelog data is missing. "
  1568. "If the error persists the replica must be reinitialized.");
  1569. return_value = UPDATE_TRANSIENT_ERROR;
  1570. break;
  1571. case CL5_UNKNOWN_ERROR: /* unclassified error */
  1572. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1573. "send_updates - %s: An unknown error was encountered\n",
  1574. agmt_get_long_name(prp->agmt));
  1575. return_value = UPDATE_TRANSIENT_ERROR;
  1576. break;
  1577. default:
  1578. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1579. "send_updates - %s: An unknown error (%d) occurred "
  1580. "(cl5CreateReplayIterator)\n",
  1581. agmt_get_long_name(prp->agmt), rc);
  1582. return_value = UPDATE_TRANSIENT_ERROR;
  1583. }
  1584. } else {
  1585. ConnResult replay_crc;
  1586. Replica *replica = (Replica *)object_get_data(prp->replica_object);
  1587. PRBool subentry_update_needed = PR_FALSE;
  1588. PRUint64 release_timeout = replica_get_release_timeout(replica);
  1589. char csn_str[CSN_STRSIZE];
  1590. int skipped_updates = 0;
  1591. int fractional_repl;
  1592. int finished = 0;
  1593. #define FRACTIONAL_SKIPPED_THRESHOLD 100
  1594. /* Start the results reading thread */
  1595. rd = repl5_inc_rd_new(prp);
  1596. if (!prp->repl50consumer) {
  1597. rc = repl5_inc_create_async_result_thread(rd);
  1598. if (rc) {
  1599. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name, "send_updates - %s: "
  1600. "repl5_inc_create_async_result_thread failed; error - %d\n",
  1601. agmt_get_long_name(prp->agmt), rc);
  1602. agmt_set_last_update_status(prp->agmt, 0, rc, "Failed to create result thread");
  1603. return_value = UPDATE_FATAL_ERROR;
  1604. }
  1605. }
  1606. memset((void *)&op, 0, sizeof(op));
  1607. entry.op = &op;
  1608. fractional_repl = agmt_is_fractional(prp->agmt);
  1609. do {
  1610. cl5_operation_parameters_done(entry.op);
  1611. memset((void *)entry.op, 0, sizeof(op));
  1612. rc = cl5GetNextOperationToReplay(changelog_iterator, &entry);
  1613. switch (rc) {
  1614. case CL5_SUCCESS:
  1615. /* check that we don't return dummy entries */
  1616. if (is_dummy_operation(entry.op)) {
  1617. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1618. "send_updates - %s: changelog iteration code returned a dummy entry with csn %s, "
  1619. "skipping ...\n",
  1620. agmt_get_long_name(prp->agmt), csn_as_string(entry.op->csn, PR_FALSE, csn_str));
  1621. continue;
  1622. }
  1623. replay_crc = replay_update(prp, entry.op, &message_id);
  1624. if (message_id) {
  1625. rd->last_message_id_sent = message_id;
  1626. }
  1627. /* If we're talking to an old non-async replica, we need to pick up the response here */
  1628. if (CONN_OPERATION_SUCCESS != replay_crc) {
  1629. int operation, error;
  1630. conn_get_error(prp->conn, &operation, &error);
  1631. csn_as_string(entry.op->csn, PR_FALSE, csn_str);
  1632. /* Figure out what to do next */
  1633. if (CONN_OPERATION_FAILED == replay_crc) {
  1634. /* Map ldap error code to return value */
  1635. if (!ignore_error_and_keep_going(error)) {
  1636. return_value = UPDATE_TRANSIENT_ERROR;
  1637. finished = 1;
  1638. } else {
  1639. agmt_inc_last_update_changecount(prp->agmt, csn_get_replicaid(entry.op->csn), 1 /*skipped*/);
  1640. }
  1641. slapi_log_err(finished ? SLAPI_LOG_WARNING : slapi_log_urp,
  1642. "send_updates - %s: Failed to send update operation to consumer (uniqueid %s, CSN %s): %s. %s.\n",
  1643. (char *)agmt_get_long_name(prp->agmt),
  1644. entry.op->target_address.uniqueid, csn_str,
  1645. ldap_err2string(error),
  1646. finished ? "Will retry later" : "Skipping");
  1647. } else if (CONN_NOT_CONNECTED == replay_crc) {
  1648. /* We lost the connection - enter backoff state */
  1649. return_value = UPDATE_CONNECTION_LOST;
  1650. finished = 1;
  1651. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1652. "send_updates - %s: Failed to send update operation to consumer (uniqueid %s, CSN %s): "
  1653. "%s. Will retry later.\n",
  1654. agmt_get_long_name(prp->agmt),
  1655. entry.op->target_address.uniqueid, csn_str,
  1656. error ? ldap_err2string(error) : "Connection lost");
  1657. } else if (CONN_TIMEOUT == replay_crc) {
  1658. return_value = UPDATE_TIMEOUT;
  1659. finished = 1;
  1660. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1661. "send_updates - %s: Timed out sending update operation to consumer (uniqueid %s, CSN %s): "
  1662. "%s.\n",
  1663. agmt_get_long_name(prp->agmt),
  1664. entry.op->target_address.uniqueid, csn_str,
  1665. error ? ldap_err2string(error) : "Timeout");
  1666. } else if (CONN_LOCAL_ERROR == replay_crc) {
  1667. /*
  1668. * Something bad happened on the local server - enter
  1669. * backoff state.
  1670. */
  1671. return_value = UPDATE_TRANSIENT_ERROR;
  1672. finished = 1;
  1673. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1674. "send_updates - %s: Failed to send update operation to consumer (uniqueid %s, CSN %s): "
  1675. "Local error. Will retry later.\n",
  1676. agmt_get_long_name(prp->agmt),
  1677. entry.op->target_address.uniqueid, csn_str);
  1678. }
  1679. } else {
  1680. char *uniqueid = NULL;
  1681. ReplicaId replica_id = 0;
  1682. csn_as_string(entry.op->csn, PR_FALSE, csn_str);
  1683. replica_id = csn_get_replicaid(entry.op->csn);
  1684. uniqueid = entry.op->target_address.uniqueid;
  1685. if (fractional_repl && message_id) {
  1686. /* This update was sent no need to update the subentry
  1687. * and restart counting the skipped updates
  1688. */
  1689. subentry_update_needed = PR_FALSE;
  1690. skipped_updates = 0;
  1691. }
  1692. if (prp->repl50consumer && message_id) {
  1693. int operation, error = 0;
  1694. conn_get_error(prp->conn, &operation, &error);
  1695. /* Get the response here */
  1696. replay_crc = repl5_inc_get_next_result(rd);
  1697. conn_get_error(prp->conn, &operation, &error);
  1698. csn_as_string(entry.op->csn, PR_FALSE, csn_str);
  1699. return_value = repl5_inc_update_from_op_result(prp, replay_crc, error, csn_str, uniqueid, replica_id, &finished, num_changes_sent);
  1700. } else if (message_id) {
  1701. /* Queue the details for pickup later in the response thread */
  1702. repl5_inc_operation *sop = NULL;
  1703. sop = repl5_inc_operation_new();
  1704. PL_strncpyz(sop->csn_str, csn_str, sizeof(sop->csn_str));
  1705. sop->ldap_message_id = message_id;
  1706. sop->operation_type = entry.op->operation_type;
  1707. sop->replica_id = replica_id;
  1708. PL_strncpyz(sop->uniqueid, uniqueid, sizeof(sop->uniqueid));
  1709. repl5_int_push_operation(rd, sop);
  1710. repl5_inc_flow_control_results(prp->agmt, rd);
  1711. } else {
  1712. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1713. "send_updates - %s: Skipping update operation with no message_id (uniqueid %s, CSN %s):\n",
  1714. agmt_get_long_name(prp->agmt),
  1715. entry.op->target_address.uniqueid, csn_str);
  1716. agmt_inc_last_update_changecount(prp->agmt, csn_get_replicaid(entry.op->csn), 1 /*skipped*/);
  1717. if (fractional_repl) {
  1718. skipped_updates++;
  1719. if (skipped_updates > FRACTIONAL_SKIPPED_THRESHOLD) {
  1720. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1721. "send_updates - %s: skipped updates is too high (%d) if no other update is sent we will update the subentry\n",
  1722. agmt_get_long_name(prp->agmt), skipped_updates);
  1723. subentry_update_needed = PR_TRUE;
  1724. }
  1725. }
  1726. }
  1727. }
  1728. break;
  1729. case CL5_BAD_DATA:
  1730. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1731. "send_updates - %s: Invalid parameter passed to cl5GetNextOperationToReplay\n",
  1732. agmt_get_long_name(prp->agmt));
  1733. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1734. "Invalid parameter passed to cl5GetNextOperationToReplay");
  1735. return_value = UPDATE_FATAL_ERROR;
  1736. finished = 1;
  1737. break;
  1738. case CL5_NOTFOUND:
  1739. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1740. "send_updates - %s: No more updates to send (cl5GetNextOperationToReplay)\n",
  1741. agmt_get_long_name(prp->agmt));
  1742. return_value = UPDATE_NO_MORE_UPDATES;
  1743. finished = 1;
  1744. break;
  1745. case CL5_DB_ERROR:
  1746. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1747. "send_updates - %s: A database error occurred (cl5GetNextOperationToReplay)\n",
  1748. agmt_get_long_name(prp->agmt));
  1749. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1750. "Database error occurred while getting the next operation to replay");
  1751. return_value = UPDATE_FATAL_ERROR;
  1752. finished = 1;
  1753. break;
  1754. case CL5_BAD_FORMAT:
  1755. slapi_log_err(SLAPI_LOG_WARNING, repl_plugin_name,
  1756. "send_updates - %s: A malformed changelog entry was encountered (cl5GetNextOperationToReplay)\n",
  1757. agmt_get_long_name(prp->agmt));
  1758. break;
  1759. case CL5_MEMORY_ERROR:
  1760. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1761. "send_updates - %s: A memory allocation error occurred (cl5GetNextOperationToReplay)\n",
  1762. agmt_get_long_name(prp->agmt));
  1763. agmt_set_last_update_status(prp->agmt, 0, NSDS50_REPL_CL_ERROR,
  1764. "Memory allocation error occurred (cl5GetNextOperationToReplay)");
  1765. return_value = UPDATE_FATAL_ERROR;
  1766. break;
  1767. case CL5_IGNORE_OP:
  1768. break;
  1769. default:
  1770. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1771. "send_updates - %s: Unknown error code (%d) returned from cl5GetNextOperationToReplay\n",
  1772. agmt_get_long_name(prp->agmt), rc);
  1773. return_value = UPDATE_TRANSIENT_ERROR;
  1774. break;
  1775. }
  1776. /* Check for protocol shutdown */
  1777. if (prp->terminate) {
  1778. return_value = UPDATE_NO_MORE_UPDATES;
  1779. finished = 1;
  1780. }
  1781. if (*num_changes_sent >= MAX_CHANGES_PER_SESSION) {
  1782. return_value = UPDATE_YIELD;
  1783. finished = 1;
  1784. }
  1785. PR_Lock(rd->lock);
  1786. /* See if the result thread has hit a problem */
  1787. if (!finished && rd->abort_time) {
  1788. time_t current_time = slapi_current_utc_time();
  1789. if ((current_time - rd->abort_time) >= release_timeout) {
  1790. rd->result = UPDATE_YIELD;
  1791. return_value = UPDATE_YIELD;
  1792. finished = 1;
  1793. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1794. "send_updates - Aborting send_updates...(%s)\n",
  1795. agmt_get_long_name(rd->prp->agmt));
  1796. }
  1797. }
  1798. if (!finished && rd->abort == ABORT_SESSION) {
  1799. return_value = rd->result;
  1800. finished = 1;
  1801. }
  1802. PR_Unlock(rd->lock);
  1803. } while (!finished);
  1804. if (fractional_repl && subentry_update_needed) {
  1805. ReplicaId rid = -1; /* Used to create the replica keep alive subentry */
  1806. Slapi_DN *replarea_sdn = NULL;
  1807. if (replica) {
  1808. rid = replica_get_rid(replica);
  1809. }
  1810. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1811. "send_updates - %s: skipped updates was definitely too high (%d) update the subentry now\n",
  1812. agmt_get_long_name(prp->agmt), skipped_updates);
  1813. replarea_sdn = agmt_get_replarea(prp->agmt);
  1814. if (!replarea_sdn) {
  1815. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name,
  1816. "send_updates - Unknown replication area due to agreement not found.");
  1817. agmt_set_last_update_status(prp->agmt, 0, -1, "Agreement is corrupted: missing suffix");
  1818. return_value = UPDATE_FATAL_ERROR;
  1819. } else {
  1820. replica_subentry_update(replarea_sdn, rid);
  1821. }
  1822. }
  1823. /* Terminate the results reading thread */
  1824. if (!prp->repl50consumer) {
  1825. /* We need to ensure that we wait until all the responses have been received from our operations */
  1826. if (return_value != UPDATE_CONNECTION_LOST) {
  1827. /*
  1828. * If we already have an error, there is no need to check the
  1829. * async result thread anymore.
  1830. */
  1831. if (return_value == UPDATE_NO_MORE_UPDATES || return_value == UPDATE_YIELD) {
  1832. /*
  1833. * We need to double check that an error hasn't popped up from
  1834. * the async result thread since our last check.
  1835. */
  1836. int final_result;
  1837. rd->WaitForAsyncResults = agmt_get_WaitForAsyncResults(prp->agmt);
  1838. if ((final_result = repl5_inc_waitfor_async_results(rd))) {
  1839. return_value = final_result;
  1840. }
  1841. }
  1842. }
  1843. rc = repl5_inc_destroy_async_result_thread(rd);
  1844. if (rc) {
  1845. slapi_log_err(SLAPI_LOG_ERR, repl_plugin_name, "%s: repl5_inc_run: "
  1846. "send_updates - repl5_inc_destroy_async_result_thread failed; error - %d\n",
  1847. agmt_get_long_name(prp->agmt), rc);
  1848. }
  1849. *num_changes_sent = rd->num_changes_sent;
  1850. }
  1851. PR_Lock(rd->lock);
  1852. if (rd->flowcontrol_detection) {
  1853. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1854. "send_updates - %s: Incremental update flow control triggered %d times\n"
  1855. "You may increase %s and/or decrease %s in the replica agreement configuration\n",
  1856. agmt_get_long_name(prp->agmt),
  1857. rd->flowcontrol_detection,
  1858. type_nsds5ReplicaFlowControlPause,
  1859. type_nsds5ReplicaFlowControlWindow);
  1860. }
  1861. PR_Unlock(rd->lock);
  1862. repl5_inc_rd_destroy(&rd);
  1863. cl5_operation_parameters_done(entry.op);
  1864. cl5DestroyReplayIterator(&changelog_iterator);
  1865. }
  1866. return return_value;
  1867. }
  1868. /*
  1869. * XXXggood this should probably be in the superclass, since the full update
  1870. * protocol is going to need it too.
  1871. */
  1872. static int
  1873. repl5_inc_stop(Private_Repl_Protocol *prp)
  1874. {
  1875. PRIntervalTime start, maxwait, now;
  1876. Replica *replica = NULL;
  1877. PRUint64 timeout;
  1878. int return_value;
  1879. if ((timeout = agmt_get_protocol_timeout(prp->agmt)) == 0) {
  1880. timeout = DEFAULT_PROTOCOL_TIMEOUT;
  1881. if (prp->replica_object) {
  1882. object_acquire(prp->replica_object);
  1883. replica = object_get_data(prp->replica_object);
  1884. if ((timeout = replica_get_protocol_timeout(replica)) == 0) {
  1885. timeout = DEFAULT_PROTOCOL_TIMEOUT;
  1886. }
  1887. object_release(prp->replica_object);
  1888. }
  1889. }
  1890. maxwait = PR_SecondsToInterval(timeout);
  1891. prp->terminate = 1;
  1892. event_notify(prp, EVENT_PROTOCOL_SHUTDOWN);
  1893. start = PR_IntervalNow();
  1894. now = start;
  1895. while (!prp->stopped && ((now - start) < maxwait)) {
  1896. DS_Sleep(PR_MillisecondsToInterval(100));
  1897. now = PR_IntervalNow();
  1898. }
  1899. if (!prp->stopped) {
  1900. /* Isn't listening. Do something drastic. */
  1901. return_value = -1;
  1902. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1903. "repl5_inc_stop - %s: Protocol does not stop after %" PRIu64 " seconds\n",
  1904. agmt_get_long_name(prp->agmt), timeout);
  1905. } else {
  1906. return_value = 0;
  1907. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1908. "repl5_inc_stop - %s: Protocol stopped after %d seconds\n",
  1909. agmt_get_long_name(prp->agmt),
  1910. PR_IntervalToSeconds(now - start));
  1911. }
  1912. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1913. if (NULL == prp->replica_object) {
  1914. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1915. "repl5_inc_stop - %s: Protocol replica_object is NULL\n",
  1916. agmt_get_long_name(prp->agmt));
  1917. } else {
  1918. Replica *replica;
  1919. object_acquire(prp->replica_object);
  1920. replica = object_get_data(prp->replica_object);
  1921. if (NULL == replica) {
  1922. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1923. "repl5_inc_stop - %s:replica is NULL\n",
  1924. agmt_get_long_name(prp->agmt));
  1925. } else {
  1926. Object *ruv_obj = replica_get_ruv(replica);
  1927. if (NULL == ruv_obj) {
  1928. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1929. "repl5_inc_stop - %s: rruv_obj is NULL\n",
  1930. agmt_get_long_name(prp->agmt));
  1931. } else {
  1932. RUV *ruv;
  1933. object_acquire(ruv_obj);
  1934. ruv = (RUV *)object_get_data(ruv_obj);
  1935. if (NULL == ruv) {
  1936. slapi_log_err(SLAPI_LOG_REPL, repl_plugin_name,
  1937. "repl5_inc_stop - %s: ruv is NULL\n",
  1938. agmt_get_long_name(prp->agmt));
  1939. } else {
  1940. ruv_dump(ruv, "Database RUV", NULL);
  1941. }
  1942. object_release(ruv_obj);
  1943. }
  1944. }
  1945. object_release(prp->replica_object);
  1946. }
  1947. }
  1948. return return_value;
  1949. }
  1950. static int
  1951. repl5_inc_status(Private_Repl_Protocol *prp __attribute__((unused)))
  1952. {
  1953. int return_value = 0;
  1954. return return_value;
  1955. }
  1956. static void
  1957. repl5_inc_notify_update(Private_Repl_Protocol *prp)
  1958. {
  1959. event_notify(prp, EVENT_TRIGGERING_CRITERIA_MET);
  1960. }
  1961. static void
  1962. repl5_inc_update_now(Private_Repl_Protocol *prp)
  1963. {
  1964. event_notify(prp, EVENT_REPLICATE_NOW);
  1965. }
  1966. static void
  1967. repl5_inc_notify_agmt_changed(Private_Repl_Protocol *prp)
  1968. {
  1969. event_notify(prp, EVENT_AGMT_CHANGED);
  1970. }
  1971. static void
  1972. repl5_inc_notify_window_opened(Private_Repl_Protocol *prp)
  1973. {
  1974. event_notify(prp, EVENT_WINDOW_OPENED);
  1975. }
  1976. static void
  1977. repl5_inc_notify_window_closed(Private_Repl_Protocol *prp)
  1978. {
  1979. event_notify(prp, EVENT_WINDOW_CLOSED);
  1980. }
  1981. Private_Repl_Protocol *
  1982. Repl_5_Inc_Protocol_new(Repl_Protocol *rp)
  1983. {
  1984. repl5_inc_private *rip = NULL;
  1985. Private_Repl_Protocol *prp = (Private_Repl_Protocol *)slapi_ch_malloc(sizeof(Private_Repl_Protocol));
  1986. prp->delete = repl5_inc_delete;
  1987. prp->run = repl5_inc_run;
  1988. prp->stop = repl5_inc_stop;
  1989. prp->status = repl5_inc_status;
  1990. prp->notify_update = repl5_inc_notify_update;
  1991. prp->notify_agmt_changed = repl5_inc_notify_agmt_changed;
  1992. prp->notify_window_opened = repl5_inc_notify_window_opened;
  1993. prp->notify_window_closed = repl5_inc_notify_window_closed;
  1994. prp->update_now = repl5_inc_update_now;
  1995. prp->replica_object = prot_get_replica_object(rp);
  1996. if ((prp->lock = PR_NewLock()) == NULL) {
  1997. goto loser;
  1998. }
  1999. if ((prp->cvar = PR_NewCondVar(prp->lock)) == NULL) {
  2000. goto loser;
  2001. }
  2002. prp->stopped = 0;
  2003. prp->terminate = 0;
  2004. prp->eventbits = 0;
  2005. prp->conn = prot_get_connection(rp);
  2006. prp->agmt = prot_get_agreement(rp);
  2007. prp->last_acquire_response_code = NSDS50_REPL_REPLICA_READY;
  2008. rip = (void *)slapi_ch_malloc(sizeof(repl5_inc_private));
  2009. rip->ruv = NULL;
  2010. rip->backoff = NULL;
  2011. rip->rp = rp;
  2012. prp->private = (void *)rip;
  2013. prp->replica_acquired = PR_FALSE;
  2014. prp->repl50consumer = 0;
  2015. prp->repl71consumer = 0;
  2016. prp->repl90consumer = 0;
  2017. return prp;
  2018. loser:
  2019. repl5_inc_delete(&prp);
  2020. return NULL;
  2021. }
  2022. static void
  2023. repl5_inc_backoff_expired(time_t timer_fire_time __attribute__((unused)), void *arg)
  2024. {
  2025. Private_Repl_Protocol *prp = (Private_Repl_Protocol *)arg;
  2026. PR_ASSERT(NULL != prp);
  2027. event_notify(prp, EVENT_BACKOFF_EXPIRED);
  2028. }
  2029. /*
  2030. * Examine the update vector and determine our course of action.
  2031. * There are 3 different possibilities, plus a catch-all error:
  2032. * 1 - no update vector (ruv is NULL). The consumer's replica is
  2033. * pristine, so it needs to be initialized. Return
  2034. * EXAMINE_RUV_PRISTINE_REPLICA.
  2035. * 2 - ruv is present, but its database generation ID doesn't
  2036. * match the local generation ID. This means that either
  2037. * the local replica must be reinitialized from the remote
  2038. * replica or vice-versa. Return
  2039. * EXAMINE_RUV_GENERATION_MISMATCH.
  2040. * 3 - ruv is present, and we have all updates needed to bring
  2041. * the replica up to date using the incremental protocol.
  2042. * return EXAMINE_RUV_OK.
  2043. * 4 - parameter error. Return EXAMINE_RUV_PARAM_ERROR
  2044. */
  2045. static int
  2046. examine_update_vector(Private_Repl_Protocol *prp, RUV *remote_ruv)
  2047. {
  2048. int return_value;
  2049. PR_ASSERT(NULL != prp);
  2050. if (NULL == prp) {
  2051. return_value = EXAMINE_RUV_PARAM_ERROR;
  2052. } else if (NULL == remote_ruv) {
  2053. return_value = EXAMINE_RUV_PRISTINE_REPLICA;
  2054. } else {
  2055. char *local_gen = NULL;
  2056. char *remote_gen = ruv_get_replica_generation(remote_ruv);
  2057. Object *local_ruv_obj;
  2058. RUV *local_ruv;
  2059. Replica *replica;
  2060. PR_ASSERT(NULL != prp->replica_object);
  2061. replica = object_get_data(prp->replica_object);
  2062. PR_ASSERT(NULL != replica);
  2063. local_ruv_obj = replica_get_ruv(replica);
  2064. if (NULL != local_ruv_obj) {
  2065. local_ruv = (RUV *)object_get_data(local_ruv_obj);
  2066. PR_ASSERT(local_ruv);
  2067. local_gen = ruv_get_replica_generation(local_ruv);
  2068. object_release(local_ruv_obj);
  2069. }
  2070. if (NULL == remote_gen || NULL == local_gen || strcmp(remote_gen, local_gen) != 0) {
  2071. return_value = EXAMINE_RUV_GENERATION_MISMATCH;
  2072. } else {
  2073. return_value = EXAMINE_RUV_OK;
  2074. }
  2075. slapi_ch_free((void **)&remote_gen);
  2076. slapi_ch_free((void **)&local_gen);
  2077. }
  2078. return return_value;
  2079. }
  2080. /*
  2081. * When we get an error from an LDAP operation, we call this
  2082. * function to decide if we should just keep replaying
  2083. * updates, or if we should stop, back off, and try again
  2084. * later.
  2085. * Returns PR_TRUE if we shoould keep going, PR_FALSE if
  2086. * we should back off and try again later.
  2087. *
  2088. * In general, we keep going if the return code is consistent
  2089. * with some sort of bug in URP that causes the consumer to
  2090. * emit an error code that it shouldn't have, e.g. LDAP_ALREADY_EXISTS.
  2091. *
  2092. * We stop if there's some indication that the server just completely
  2093. * failed to process the operation, e.g. LDAP_OPERATIONS_ERROR.
  2094. */
  2095. PRBool
  2096. ignore_error_and_keep_going(int error)
  2097. {
  2098. int return_value = PR_FALSE;
  2099. switch (error) {
  2100. /* Cases where we keep going */
  2101. case LDAP_SUCCESS:
  2102. case LDAP_NO_SUCH_ATTRIBUTE:
  2103. case LDAP_UNDEFINED_TYPE:
  2104. case LDAP_CONSTRAINT_VIOLATION:
  2105. case LDAP_TYPE_OR_VALUE_EXISTS:
  2106. case LDAP_INVALID_SYNTAX:
  2107. case LDAP_NO_SUCH_OBJECT:
  2108. case LDAP_INVALID_DN_SYNTAX:
  2109. case LDAP_IS_LEAF:
  2110. case LDAP_INSUFFICIENT_ACCESS:
  2111. case LDAP_NAMING_VIOLATION:
  2112. case LDAP_OBJECT_CLASS_VIOLATION:
  2113. case LDAP_NOT_ALLOWED_ON_NONLEAF:
  2114. case LDAP_NOT_ALLOWED_ON_RDN:
  2115. case LDAP_ALREADY_EXISTS:
  2116. case LDAP_NO_OBJECT_CLASS_MODS:
  2117. return_value = PR_TRUE;
  2118. break;
  2119. /* Cases where we stop and retry */
  2120. case LDAP_OPERATIONS_ERROR:
  2121. case LDAP_PROTOCOL_ERROR:
  2122. case LDAP_TIMELIMIT_EXCEEDED:
  2123. case LDAP_SIZELIMIT_EXCEEDED:
  2124. case LDAP_STRONG_AUTH_NOT_SUPPORTED:
  2125. case LDAP_STRONG_AUTH_REQUIRED:
  2126. case LDAP_PARTIAL_RESULTS:
  2127. case LDAP_REFERRAL:
  2128. case LDAP_ADMINLIMIT_EXCEEDED:
  2129. case LDAP_UNAVAILABLE_CRITICAL_EXTENSION:
  2130. case LDAP_CONFIDENTIALITY_REQUIRED:
  2131. case LDAP_SASL_BIND_IN_PROGRESS:
  2132. case LDAP_INAPPROPRIATE_MATCHING:
  2133. case LDAP_ALIAS_PROBLEM:
  2134. case LDAP_ALIAS_DEREF_PROBLEM:
  2135. case LDAP_INAPPROPRIATE_AUTH:
  2136. case LDAP_INVALID_CREDENTIALS:
  2137. case LDAP_BUSY:
  2138. case LDAP_UNAVAILABLE:
  2139. case LDAP_UNWILLING_TO_PERFORM:
  2140. case LDAP_LOOP_DETECT:
  2141. case LDAP_SORT_CONTROL_MISSING:
  2142. case LDAP_INDEX_RANGE_ERROR:
  2143. case LDAP_RESULTS_TOO_LARGE:
  2144. case LDAP_AFFECTS_MULTIPLE_DSAS:
  2145. case LDAP_OTHER:
  2146. case LDAP_SERVER_DOWN:
  2147. case LDAP_LOCAL_ERROR:
  2148. case LDAP_ENCODING_ERROR:
  2149. case LDAP_DECODING_ERROR:
  2150. case LDAP_TIMEOUT:
  2151. case LDAP_AUTH_UNKNOWN:
  2152. case LDAP_FILTER_ERROR:
  2153. case LDAP_USER_CANCELLED:
  2154. case LDAP_PARAM_ERROR:
  2155. case LDAP_NO_MEMORY:
  2156. case LDAP_CONNECT_ERROR:
  2157. case LDAP_NOT_SUPPORTED:
  2158. case LDAP_CONTROL_NOT_FOUND:
  2159. case LDAP_NO_RESULTS_RETURNED:
  2160. case LDAP_MORE_RESULTS_TO_RETURN:
  2161. case LDAP_CLIENT_LOOP:
  2162. case LDAP_REFERRAL_LIMIT_EXCEEDED:
  2163. return_value = PR_FALSE;
  2164. break;
  2165. }
  2166. return return_value;
  2167. }
  2168. /* this function converts a state to its name - for debug output */
  2169. static const char *
  2170. state2name(int state)
  2171. {
  2172. switch (state) {
  2173. case STATE_START:
  2174. return "start";
  2175. case STATE_WAIT_WINDOW_OPEN:
  2176. return "wait_for_window_to_open";
  2177. case STATE_WAIT_CHANGES:
  2178. return "wait_for_changes";
  2179. case STATE_READY_TO_ACQUIRE:
  2180. return "ready_to_acquire_replica";
  2181. case STATE_BACKOFF_START:
  2182. return "start_backoff";
  2183. case STATE_BACKOFF:
  2184. return "backoff";
  2185. case STATE_SENDING_UPDATES:
  2186. return "sending_updates";
  2187. case STATE_STOP_FATAL_ERROR:
  2188. return "stop_fatal_error";
  2189. case STATE_STOP_FATAL_ERROR_PART2:
  2190. return "stop_fatal_error";
  2191. case STATE_STOP_NORMAL_TERMINATION:
  2192. return "stop_normal_termination";
  2193. default:
  2194. return "invalid_state";
  2195. }
  2196. }
  2197. /* this function convert s an event to its name - for debug output */
  2198. static const char *
  2199. event2name(int event)
  2200. {
  2201. switch (event) {
  2202. case EVENT_WINDOW_OPENED:
  2203. return "update_window_opened";
  2204. case EVENT_WINDOW_CLOSED:
  2205. return "update_window_closed";
  2206. case EVENT_TRIGGERING_CRITERIA_MET:
  2207. return "data_modified";
  2208. case EVENT_BACKOFF_EXPIRED:
  2209. return "backoff_timer_expired";
  2210. case EVENT_REPLICATE_NOW:
  2211. return "replicate_now";
  2212. case EVENT_PROTOCOL_SHUTDOWN:
  2213. return "protocol_shutdown";
  2214. case EVENT_AGMT_CHANGED:
  2215. return "agreement_changed";
  2216. default:
  2217. return "invalid_event";
  2218. }
  2219. }
  2220. static const char *
  2221. op2string(int op)
  2222. {
  2223. switch (op) {
  2224. case SLAPI_OPERATION_ADD:
  2225. return "add";
  2226. case SLAPI_OPERATION_MODIFY:
  2227. return "modify";
  2228. case SLAPI_OPERATION_DELETE:
  2229. return "delete";
  2230. case SLAPI_OPERATION_MODRDN:
  2231. return "rename";
  2232. case SLAPI_OPERATION_EXTENDED:
  2233. return "extended";
  2234. }
  2235. return "unknown";
  2236. }
  2237. void
  2238. repl5_set_backoff_min(Private_Repl_Protocol *prp, int min)
  2239. {
  2240. Replica *replica;
  2241. replica = (Replica *)object_get_data(prp->replica_object);
  2242. if (replica) {
  2243. replica_set_backoff_min(replica, min);
  2244. }
  2245. }
  2246. void
  2247. repl5_set_backoff_max(Private_Repl_Protocol *prp, int max)
  2248. {
  2249. Replica *replica;
  2250. replica = object_get_data(prp->replica_object);
  2251. if (replica) {
  2252. replica_set_backoff_max(replica, max);
  2253. }
  2254. }
  2255. int
  2256. repl5_get_backoff_min(Private_Repl_Protocol *prp)
  2257. {
  2258. Replica *replica;
  2259. replica = object_get_data(prp->replica_object);
  2260. if (replica) {
  2261. return (int)replica_get_backoff_min(replica);
  2262. }
  2263. return PROTOCOL_BACKOFF_MINIMUM;
  2264. }
  2265. int
  2266. repl5_get_backoff_max(Private_Repl_Protocol *prp)
  2267. {
  2268. Replica *replica;
  2269. replica = object_get_data(prp->replica_object);
  2270. if (replica) {
  2271. return (int)replica_get_backoff_max(replica);
  2272. }
  2273. return PROTOCOL_BACKOFF_MAXIMUM;
  2274. }