repl5_inc_protocol.c 89 KB

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