repl5_inc_protocol.c 89 KB

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