Monitor

From Gerardo Barajas, 5 Months ago, written in Plain Text, viewed 56 times.
URL http://pastebin.freepbx.org/view/c87df0d9 Embed
Download Paste or View Raw
  1. ...
  2. [2017-08-16 11:45:01,506] (fs) DEBUG - timeout waiting for messages on queue
  3. [2017-08-16 11:45:01,506] (fs) DEBUG - fsmainloop receiving message..
  4. [2017-08-16 11:45:01,635] (cluster) DEBUG - updating all information...
  5. [2017-08-16 11:45:01,636] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  6. [2017-08-16 11:45:01,651] (db) DEBUG - creating new DB connection...
  7. [2017-08-16 11:45:01,653] (db) DEBUG - users already verified..
  8. [2017-08-16 11:45:01,654] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  9. [2017-08-16 11:45:01,654] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  10. [2017-08-16 11:45:01,670] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  11. [2017-08-16 11:45:01,671] (db) DEBUG - closing DB connection...
  12. [2017-08-16 11:45:01,672] (db) DEBUG - mariadb status: running
  13. [2017-08-16 11:45:01,675] (root) DEBUG - no events on inotify watcher
  14. [2017-08-16 11:45:01,676] (cluster) DEBUG - update cibmap called (force=True)
  15. [2017-08-16 11:45:01,707] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  16. [2017-08-16 11:45:03,506] (fs) DEBUG - timeout waiting for messages on queue
  17. [2017-08-16 11:45:03,507] (fs) DEBUG - fsmainloop receiving message..
  18. [2017-08-16 11:45:03,708] (cluster) DEBUG - updating all information...
  19. [2017-08-16 11:45:03,708] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  20. [2017-08-16 11:45:03,728] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  21. [2017-08-16 11:45:03,748] (root) DEBUG - no events on inotify watcher
  22. [2017-08-16 11:45:03,749] (cluster) DEBUG - update cibmap called (force=False)
  23. [2017-08-16 11:45:03,749] (cluster) DEBUG - cib not changed, looping...
  24. [2017-08-16 11:45:05,320] (server) DEBUG - accepting new connection...
  25. [2017-08-16 11:45:05,321] (request) DEBUG - handling connection from ('127.0.0.1', 45788)
  26. [2017-08-16 11:45:05,321] (request) DEBUG - received request: ['STATUS']
  27. [2017-08-16 11:45:05,321] (request) DEBUG - querying status from led...
  28. [2017-08-16 11:45:05,321] (request) DEBUG - querying status from fs...
  29. [2017-08-16 11:45:05,321] (request) DEBUG - querying status from db...
  30. [2017-08-16 11:45:05,321] (request) DEBUG - querying status from mon...
  31. [2017-08-16 11:45:05,321] (request) DEBUG - querying status from cluster...
  32. [2017-08-16 11:45:05,507] (fs) DEBUG - timeout waiting for messages on queue
  33. [2017-08-16 11:45:05,507] (fs) DEBUG - fsmainloop receiving message..
  34. [2017-08-16 11:45:05,672] (db) DEBUG - creating new DB connection...
  35. [2017-08-16 11:45:05,674] (db) DEBUG - users already verified..
  36. [2017-08-16 11:45:05,674] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  37. [2017-08-16 11:45:05,676] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  38. [2017-08-16 11:45:05,677] (db) DEBUG - closing DB connection...
  39. [2017-08-16 11:45:05,677] (db) DEBUG - mariadb status: running
  40. [2017-08-16 11:45:05,749] (cluster) DEBUG - updating all information...
  41. [2017-08-16 11:45:05,749] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  42. [2017-08-16 11:45:05,769] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  43. [2017-08-16 11:45:05,793] (root) DEBUG - WD=(2) MASK=(2) COOKIE=(0) LEN=(0) MASK->NAMES=['IN_MODIFY'] WATCH-PATH=[/var/sngmonit/state] FILENAME=[]
  44. [2017-08-16 11:45:05,794] (cluster) DEBUG - detected sngmonit update on filesystem
  45. [2017-08-16 11:45:05,794] (root) DEBUG - adding {'request': 'sngmonit'} to message Message()
  46. [2017-08-16 11:45:05,794] (root) DEBUG - adding {'request': 'sngmonit', 'target': 'mon'} to message Message()
  47. [2017-08-16 11:45:05,794] (root) DEBUG - sending message "Message(request=sngmonit, target=mon)" to "mon"...
  48. [2017-08-16 11:45:05,795] (root) DEBUG - no events on inotify watcher
  49. [2017-08-16 11:45:05,795] (cluster) DEBUG - update cibmap called (force=True)
  50. [2017-08-16 11:45:05,812] (monit) DEBUG - received message Message(request=sngmonit, target=mon)
  51. [2017-08-16 11:45:05,830] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  52. [2017-08-16 11:45:07,507] (fs) DEBUG - timeout waiting for messages on queue
  53. [2017-08-16 11:45:07,508] (fs) DEBUG - fsmainloop - pinging...
  54. [2017-08-16 11:45:07,508] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  55. [2017-08-16 11:45:07,508] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  56. [2017-08-16 11:45:07,508] (fs) DEBUG - Connection driver esl loaded
  57. [2017-08-16 11:45:07,509] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  58. [2017-08-16 11:45:07,509] (fs) DEBUG - Initialized base connection
  59. [2017-08-16 11:45:07,509] (fs) DEBUG - Connection driver esl created
  60. [2017-08-16 11:45:07,509] (fs) DEBUG - check_connection()
  61. [2017-08-16 11:45:07,509] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  62. [2017-08-16 11:45:07,512] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  63. [2017-08-16 11:45:07,512] (fs) DEBUG - check_event(timeout=1)
  64. [2017-08-16 11:45:07,513] (fs) DEBUG - sending status message to FS...
  65. [2017-08-16 11:45:07,513] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  66. [2017-08-16 11:45:07,514] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  67. [2017-08-16 11:45:07,514] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3ae4390>: ['BACKGROUND_JOB']
  68. [2017-08-16 11:45:07,514] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  69. [2017-08-16 11:45:07,516] (fs) DEBUG - waiting event on FS...
  70. [2017-08-16 11:45:07,517] (fs) DEBUG - check_event(timeout=30000)
  71. [2017-08-16 11:45:07,517] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  72. [2017-08-16 11:45:07,517] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 42 minutes, 15 seconds, 549 milliseconds, 418 microseconds
  73. [2017-08-16 11:45:07,517] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  74. [2017-08-16 11:45:07,518] (fs) DEBUG - RESPONSE: 610646 session(s) since startup
  75. [2017-08-16 11:45:07,518] (fs) DEBUG - RESPONSE: 876 session(s) - 1 out of max 150 per sec peak 9 (2 last 5min)
  76. [2017-08-16 11:45:07,518] (fs) DEBUG - RESPONSE: 2000 session(s) max
  77. [2017-08-16 11:45:07,518] (fs) DEBUG - RESPONSE: min idle cpu 0.00/88.00
  78. [2017-08-16 11:45:07,518] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  79. [2017-08-16 11:45:07,525] (fs) DEBUG - fsmainloop receiving message..
  80. [2017-08-16 11:45:07,831] (cluster) DEBUG - updating all information...
  81. [2017-08-16 11:45:07,831] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  82. [2017-08-16 11:45:07,851] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  83. [2017-08-16 11:45:07,872] (root) DEBUG - no events on inotify watcher
  84. [2017-08-16 11:45:07,872] (cluster) DEBUG - update cibmap called (force=False)
  85. [2017-08-16 11:45:07,872] (cluster) DEBUG - cib not changed, looping...
  86. [2017-08-16 11:45:09,525] (fs) DEBUG - timeout waiting for messages on queue
  87. [2017-08-16 11:45:09,525] (fs) DEBUG - fsmainloop receiving message..
  88. [2017-08-16 11:45:09,678] (db) DEBUG - creating new DB connection...
  89. [2017-08-16 11:45:09,679] (db) DEBUG - users already verified..
  90. [2017-08-16 11:45:09,680] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  91. [2017-08-16 11:45:09,680] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  92. [2017-08-16 11:45:09,681] (db) DEBUG - closing DB connection...
  93. [2017-08-16 11:45:09,681] (db) DEBUG - mariadb status: running
  94. [2017-08-16 11:45:09,872] (cluster) DEBUG - updating all information...
  95. [2017-08-16 11:45:09,872] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  96. [2017-08-16 11:45:09,893] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  97. [2017-08-16 11:45:09,913] (root) DEBUG - no events on inotify watcher
  98. [2017-08-16 11:45:09,913] (cluster) DEBUG - update cibmap called (force=True)
  99. [2017-08-16 11:45:09,947] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  100. [2017-08-16 11:45:10,817] (monit) DEBUG - retrieving events ({'minid': 140909})...
  101. [2017-08-16 11:45:11,525] (fs) DEBUG - timeout waiting for messages on queue
  102. [2017-08-16 11:45:11,526] (fs) DEBUG - fsmainloop receiving message..
  103. [2017-08-16 11:45:11,947] (cluster) DEBUG - updating all information...
  104. [2017-08-16 11:45:11,947] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  105. [2017-08-16 11:45:11,970] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  106. [2017-08-16 11:45:11,994] (root) DEBUG - no events on inotify watcher
  107. [2017-08-16 11:45:11,994] (cluster) DEBUG - update cibmap called (force=False)
  108. [2017-08-16 11:45:11,995] (cluster) DEBUG - cib not changed, looping...
  109. [2017-08-16 11:45:13,526] (fs) DEBUG - timeout waiting for messages on queue
  110. [2017-08-16 11:45:13,526] (fs) DEBUG - fsmainloop receiving message..
  111. [2017-08-16 11:45:13,682] (db) DEBUG - creating new DB connection...
  112. [2017-08-16 11:45:13,683] (db) DEBUG - users already verified..
  113. [2017-08-16 11:45:13,683] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  114. [2017-08-16 11:45:13,684] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  115. [2017-08-16 11:45:13,685] (db) DEBUG - closing DB connection...
  116. [2017-08-16 11:45:13,685] (db) DEBUG - mariadb status: running
  117. [2017-08-16 11:45:13,995] (cluster) DEBUG - updating all information...
  118. [2017-08-16 11:45:13,995] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  119. [2017-08-16 11:45:14,020] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  120. [2017-08-16 11:45:14,041] (root) DEBUG - no events on inotify watcher
  121. [2017-08-16 11:45:14,041] (cluster) DEBUG - update cibmap called (force=True)
  122. [2017-08-16 11:45:14,074] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  123. [2017-08-16 11:45:15,526] (fs) DEBUG - timeout waiting for messages on queue
  124. [2017-08-16 11:45:15,526] (fs) DEBUG - fsmainloop receiving message..
  125. [2017-08-16 11:45:16,075] (cluster) DEBUG - updating all information...
  126. [2017-08-16 11:45:16,075] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  127. [2017-08-16 11:45:16,093] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  128. [2017-08-16 11:45:16,112] (root) DEBUG - no events on inotify watcher
  129. [2017-08-16 11:45:16,112] (cluster) DEBUG - update cibmap called (force=False)
  130. [2017-08-16 11:45:16,112] (cluster) DEBUG - cib not changed, looping...
  131. [2017-08-16 11:45:17,510] (server) DEBUG - accepting new connection...
  132. [2017-08-16 11:45:17,511] (request) DEBUG - handling connection from ('127.0.0.1', 45802)
  133. [2017-08-16 11:45:17,511] (request) DEBUG - received request: ['PING']
  134. [2017-08-16 11:45:17,511] (request) DEBUG - sending ping to cluster thread...
  135. [2017-08-16 11:45:17,511] (root) DEBUG - adding {'request': 'ping'} to message Message()
  136. [2017-08-16 11:45:17,511] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x3ab3b48>} to message Message(request=ping)
  137. [2017-08-16 11:45:17,511] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x3ab3b48>, 'request': 'ping', 'target': 'cluster'} to message Message()
  138. [2017-08-16 11:45:17,511] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x3ab3b48>, target=cluster)" to "cluster"...
  139. [2017-08-16 11:45:17,527] (fs) DEBUG - timeout waiting for messages on queue
  140. [2017-08-16 11:45:17,527] (fs) DEBUG - fsmainloop receiving message..
  141. [2017-08-16 11:45:17,528] (cluster) DEBUG - updating all information...
  142. [2017-08-16 11:45:17,528] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  143. [2017-08-16 11:45:17,545] (root) DEBUG - got acknowledge from "cluster"
  144. [2017-08-16 11:45:17,545] (request) DEBUG - got response from ping: True...
  145. [2017-08-16 11:45:17,547] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  146. [2017-08-16 11:45:17,569] (root) DEBUG - no events on inotify watcher
  147. [2017-08-16 11:45:17,569] (cluster) DEBUG - update cibmap called (force=True)
  148. [2017-08-16 11:45:17,604] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  149. [2017-08-16 11:45:17,685] (db) DEBUG - creating new DB connection...
  150. [2017-08-16 11:45:17,687] (db) DEBUG - users already verified..
  151. [2017-08-16 11:45:17,687] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  152. [2017-08-16 11:45:17,688] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  153. [2017-08-16 11:45:17,688] (db) DEBUG - closing DB connection...
  154. [2017-08-16 11:45:17,689] (db) DEBUG - mariadb status: running
  155. [2017-08-16 11:45:19,527] (fs) DEBUG - timeout waiting for messages on queue
  156. [2017-08-16 11:45:19,527] (fs) DEBUG - fsmainloop receiving message..
  157. [2017-08-16 11:45:19,605] (cluster) DEBUG - updating all information...
  158. [2017-08-16 11:45:19,605] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  159. [2017-08-16 11:45:19,628] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  160. [2017-08-16 11:45:19,651] (root) DEBUG - no events on inotify watcher
  161. [2017-08-16 11:45:19,652] (cluster) DEBUG - update cibmap called (force=False)
  162. [2017-08-16 11:45:19,652] (cluster) DEBUG - cib not changed, looping...
  163. [2017-08-16 11:45:21,527] (fs) DEBUG - timeout waiting for messages on queue
  164. [2017-08-16 11:45:21,528] (fs) DEBUG - fsmainloop receiving message..
  165. [2017-08-16 11:45:21,652] (cluster) DEBUG - updating all information...
  166. [2017-08-16 11:45:21,652] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  167. [2017-08-16 11:45:21,671] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  168. [2017-08-16 11:45:21,689] (db) DEBUG - creating new DB connection...
  169. [2017-08-16 11:45:21,691] (db) DEBUG - users already verified..
  170. [2017-08-16 11:45:21,691] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  171. [2017-08-16 11:45:21,692] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  172. [2017-08-16 11:45:21,692] (db) DEBUG - closing DB connection...
  173. [2017-08-16 11:45:21,693] (db) DEBUG - mariadb status: running
  174. [2017-08-16 11:45:21,693] (root) DEBUG - no events on inotify watcher
  175. [2017-08-16 11:45:21,693] (cluster) DEBUG - update cibmap called (force=True)
  176. [2017-08-16 11:45:21,793] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  177. [2017-08-16 11:45:23,528] (fs) DEBUG - timeout waiting for messages on queue
  178. [2017-08-16 11:45:23,528] (fs) DEBUG - fsmainloop - pinging...
  179. [2017-08-16 11:45:23,528] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  180. [2017-08-16 11:45:23,528] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  181. [2017-08-16 11:45:23,529] (fs) DEBUG - Connection driver esl loaded
  182. [2017-08-16 11:45:23,529] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  183. [2017-08-16 11:45:23,529] (fs) DEBUG - Initialized base connection
  184. [2017-08-16 11:45:23,529] (fs) DEBUG - Connection driver esl created
  185. [2017-08-16 11:45:23,529] (fs) DEBUG - check_connection()
  186. [2017-08-16 11:45:23,530] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  187. [2017-08-16 11:45:23,532] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  188. [2017-08-16 11:45:23,533] (fs) DEBUG - check_event(timeout=1)
  189. [2017-08-16 11:45:23,534] (fs) DEBUG - sending status message to FS...
  190. [2017-08-16 11:45:23,534] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  191. [2017-08-16 11:45:23,534] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  192. [2017-08-16 11:45:23,534] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x2edb3d0>: ['BACKGROUND_JOB']
  193. [2017-08-16 11:45:23,534] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  194. [2017-08-16 11:45:23,537] (fs) DEBUG - waiting event on FS...
  195. [2017-08-16 11:45:23,537] (fs) DEBUG - check_event(timeout=30000)
  196. [2017-08-16 11:45:23,537] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  197. [2017-08-16 11:45:23,537] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 42 minutes, 31 seconds, 569 milliseconds, 387 microseconds
  198. [2017-08-16 11:45:23,537] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  199. [2017-08-16 11:45:23,537] (fs) DEBUG - RESPONSE: 610708 session(s) since startup
  200. [2017-08-16 11:45:23,537] (fs) DEBUG - RESPONSE: 872 session(s) - 0 out of max 150 per sec peak 9 (2 last 5min)
  201. [2017-08-16 11:45:23,537] (fs) DEBUG - RESPONSE: 2000 session(s) max
  202. [2017-08-16 11:45:23,537] (fs) DEBUG - RESPONSE: min idle cpu 0.00/93.00
  203. [2017-08-16 11:45:23,538] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  204. [2017-08-16 11:45:23,545] (fs) DEBUG - fsmainloop receiving message..
  205. [2017-08-16 11:45:23,793] (cluster) DEBUG - updating all information...
  206. [2017-08-16 11:45:23,794] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  207. [2017-08-16 11:45:23,812] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  208. [2017-08-16 11:45:23,837] (root) DEBUG - no events on inotify watcher
  209. [2017-08-16 11:45:23,838] (cluster) DEBUG - update cibmap called (force=False)
  210. [2017-08-16 11:45:23,839] (cluster) DEBUG - cib not changed, looping...
  211. [2017-08-16 11:45:25,349] (server) DEBUG - accepting new connection...
  212. [2017-08-16 11:45:25,349] (request) DEBUG - handling connection from ('127.0.0.1', 45810)
  213. [2017-08-16 11:45:25,349] (request) DEBUG - received request: ['STATUS']
  214. [2017-08-16 11:45:25,350] (request) DEBUG - querying status from led...
  215. [2017-08-16 11:45:25,350] (request) DEBUG - querying status from fs...
  216. [2017-08-16 11:45:25,350] (request) DEBUG - querying status from db...
  217. [2017-08-16 11:45:25,350] (request) DEBUG - querying status from mon...
  218. [2017-08-16 11:45:25,350] (request) DEBUG - querying status from cluster...
  219. [2017-08-16 11:45:25,545] (fs) DEBUG - timeout waiting for messages on queue
  220. [2017-08-16 11:45:25,545] (fs) DEBUG - fsmainloop receiving message..
  221. [2017-08-16 11:45:25,693] (db) DEBUG - creating new DB connection...
  222. [2017-08-16 11:45:25,696] (db) DEBUG - users already verified..
  223. [2017-08-16 11:45:25,696] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  224. [2017-08-16 11:45:25,697] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  225. [2017-08-16 11:45:25,698] (db) DEBUG - closing DB connection...
  226. [2017-08-16 11:45:25,698] (db) DEBUG - mariadb status: running
  227. [2017-08-16 11:45:25,839] (cluster) DEBUG - updating all information...
  228. [2017-08-16 11:45:25,839] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  229. [2017-08-16 11:45:25,856] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  230. [2017-08-16 11:45:25,881] (root) DEBUG - WD=(2) MASK=(2) COOKIE=(0) LEN=(0) MASK->NAMES=['IN_MODIFY'] WATCH-PATH=[/var/sngmonit/state] FILENAME=[]
  231. [2017-08-16 11:45:25,881] (cluster) DEBUG - detected sngmonit update on filesystem
  232. [2017-08-16 11:45:25,881] (root) DEBUG - adding {'request': 'sngmonit'} to message Message()
  233. [2017-08-16 11:45:25,881] (root) DEBUG - adding {'request': 'sngmonit', 'target': 'mon'} to message Message()
  234. [2017-08-16 11:45:25,881] (root) DEBUG - sending message "Message(request=sngmonit, target=mon)" to "mon"...
  235. [2017-08-16 11:45:25,881] (root) DEBUG - no events on inotify watcher
  236. [2017-08-16 11:45:25,881] (cluster) DEBUG - update cibmap called (force=True)
  237. [2017-08-16 11:45:25,900] (monit) DEBUG - received message Message(request=sngmonit, target=mon)
  238. [2017-08-16 11:45:25,910] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  239. [2017-08-16 11:45:27,546] (fs) DEBUG - timeout waiting for messages on queue
  240. [2017-08-16 11:45:27,546] (fs) DEBUG - fsmainloop receiving message..
  241. [2017-08-16 11:45:27,911] (cluster) DEBUG - updating all information...
  242. [2017-08-16 11:45:27,911] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  243. [2017-08-16 11:45:27,930] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  244. [2017-08-16 11:45:27,950] (root) DEBUG - no events on inotify watcher
  245. [2017-08-16 11:45:27,950] (cluster) DEBUG - update cibmap called (force=False)
  246. [2017-08-16 11:45:27,950] (cluster) DEBUG - cib not changed, looping...
  247. [2017-08-16 11:45:29,546] (fs) DEBUG - timeout waiting for messages on queue
  248. [2017-08-16 11:45:29,546] (fs) DEBUG - fsmainloop receiving message..
  249. [2017-08-16 11:45:29,699] (db) DEBUG - creating new DB connection...
  250. [2017-08-16 11:45:29,700] (db) DEBUG - users already verified..
  251. [2017-08-16 11:45:29,700] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  252. [2017-08-16 11:45:29,701] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  253. [2017-08-16 11:45:29,702] (db) DEBUG - closing DB connection...
  254. [2017-08-16 11:45:29,702] (db) DEBUG - mariadb status: running
  255. [2017-08-16 11:45:29,951] (cluster) DEBUG - updating all information...
  256. [2017-08-16 11:45:29,951] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  257. [2017-08-16 11:45:29,969] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  258. [2017-08-16 11:45:29,989] (root) DEBUG - no events on inotify watcher
  259. [2017-08-16 11:45:29,989] (cluster) DEBUG - update cibmap called (force=True)
  260. [2017-08-16 11:45:30,022] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  261. [2017-08-16 11:45:30,905] (monit) DEBUG - retrieving events ({'minid': 140909})...
  262. [2017-08-16 11:45:31,547] (fs) DEBUG - timeout waiting for messages on queue
  263. [2017-08-16 11:45:31,547] (fs) DEBUG - fsmainloop receiving message..
  264. [2017-08-16 11:45:32,023] (cluster) DEBUG - updating all information...
  265. [2017-08-16 11:45:32,023] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  266. [2017-08-16 11:45:32,045] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  267. [2017-08-16 11:45:32,070] (root) DEBUG - no events on inotify watcher
  268. [2017-08-16 11:45:32,070] (cluster) DEBUG - update cibmap called (force=False)
  269. [2017-08-16 11:45:32,070] (cluster) DEBUG - cib not changed, looping...
  270. [2017-08-16 11:45:33,547] (fs) DEBUG - timeout waiting for messages on queue
  271. [2017-08-16 11:45:33,547] (fs) DEBUG - fsmainloop receiving message..
  272. [2017-08-16 11:45:33,702] (db) DEBUG - creating new DB connection...
  273. [2017-08-16 11:45:33,704] (db) DEBUG - users already verified..
  274. [2017-08-16 11:45:33,704] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  275. [2017-08-16 11:45:33,705] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  276. [2017-08-16 11:45:33,706] (db) DEBUG - closing DB connection...
  277. [2017-08-16 11:45:33,706] (db) DEBUG - mariadb status: running
  278. [2017-08-16 11:45:34,071] (cluster) DEBUG - updating all information...
  279. [2017-08-16 11:45:34,071] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  280. [2017-08-16 11:45:34,095] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  281. [2017-08-16 11:45:34,121] (root) DEBUG - no events on inotify watcher
  282. [2017-08-16 11:45:34,121] (cluster) DEBUG - update cibmap called (force=True)
  283. [2017-08-16 11:45:34,169] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  284. [2017-08-16 11:45:35,547] (fs) DEBUG - timeout waiting for messages on queue
  285. [2017-08-16 11:45:35,548] (fs) DEBUG - fsmainloop receiving message..
  286. [2017-08-16 11:45:36,169] (cluster) DEBUG - updating all information...
  287. [2017-08-16 11:45:36,170] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  288. [2017-08-16 11:45:36,201] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 23, 'stdout': 19})
  289. [2017-08-16 11:45:36,238] (root) DEBUG - no events on inotify watcher
  290. [2017-08-16 11:45:36,238] (cluster) DEBUG - update cibmap called (force=False)
  291. [2017-08-16 11:45:36,238] (cluster) DEBUG - cib not changed, looping...
  292. [2017-08-16 11:45:37,512] (server) DEBUG - accepting new connection...
  293. [2017-08-16 11:45:37,512] (request) DEBUG - handling connection from ('127.0.0.1', 45992)
  294. [2017-08-16 11:45:37,513] (request) DEBUG - received request: ['PING']
  295. [2017-08-16 11:45:37,513] (request) DEBUG - sending ping to cluster thread...
  296. [2017-08-16 11:45:37,513] (root) DEBUG - adding {'request': 'ping'} to message Message()
  297. [2017-08-16 11:45:37,513] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x3a90170>} to message Message(request=ping)
  298. [2017-08-16 11:45:37,513] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x3a90170>, 'request': 'ping', 'target': 'cluster'} to message Message()
  299. [2017-08-16 11:45:37,513] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x3a90170>, target=cluster)" to "cluster"...
  300. [2017-08-16 11:45:37,548] (fs) DEBUG - timeout waiting for messages on queue
  301. [2017-08-16 11:45:37,548] (fs) DEBUG - fsmainloop receiving message..
  302. [2017-08-16 11:45:37,555] (cluster) DEBUG - updating all information...
  303. [2017-08-16 11:45:37,556] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  304. [2017-08-16 11:45:37,577] (root) DEBUG - got acknowledge from "cluster"
  305. [2017-08-16 11:45:37,579] (request) DEBUG - got response from ping: True...
  306. [2017-08-16 11:45:37,579] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  307. [2017-08-16 11:45:37,599] (root) DEBUG - no events on inotify watcher
  308. [2017-08-16 11:45:37,600] (cluster) DEBUG - update cibmap called (force=True)
  309. [2017-08-16 11:45:37,626] (cluster) DEBUG - got master node S1-SBC01.e-contact.cl
  310. [2017-08-16 11:45:37,706] (db) DEBUG - creating new DB connection...
  311. [2017-08-16 11:45:37,708] (db) DEBUG - users already verified..
  312. [2017-08-16 11:45:37,708] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  313. [2017-08-16 11:45:37,709] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  314. [2017-08-16 11:45:37,710] (db) DEBUG - closing DB connection...
  315. [2017-08-16 11:45:37,710] (db) DEBUG - mariadb status: running
  316. [2017-08-16 11:45:39,548] (fs) DEBUG - timeout waiting for messages on queue
  317. [2017-08-16 11:45:39,549] (fs) DEBUG - fsmainloop - pinging...
  318. [2017-08-16 11:45:39,549] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  319. [2017-08-16 11:45:39,549] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  320. [2017-08-16 11:45:39,549] (fs) DEBUG - Connection driver esl loaded
  321. [2017-08-16 11:45:39,550] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  322. [2017-08-16 11:45:39,550] (fs) DEBUG - Initialized base connection
  323. [2017-08-16 11:45:39,550] (fs) DEBUG - Connection driver esl created
  324. [2017-08-16 11:45:39,552] (fs) DEBUG - check_connection()
  325. [2017-08-16 11:45:39,552] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  326. [2017-08-16 11:45:39,565] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  327. [2017-08-16 11:45:39,565] (fs) DEBUG - check_event(timeout=1)
  328. [2017-08-16 11:45:39,566] (fs) DEBUG - sending status message to FS...
  329. [2017-08-16 11:45:39,566] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  330. [2017-08-16 11:45:39,567] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  331. [2017-08-16 11:45:39,567] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x25a7ad0>: ['BACKGROUND_JOB']
  332. [2017-08-16 11:45:39,567] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  333. [2017-08-16 11:45:39,569] (fs) DEBUG - waiting event on FS...
  334. [2017-08-16 11:45:39,569] (fs) DEBUG - check_event(timeout=30000)
  335. [2017-08-16 11:45:39,569] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  336. [2017-08-16 11:45:39,570] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 42 minutes, 47 seconds, 589 milliseconds, 366 microseconds
  337. [2017-08-16 11:45:39,570] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  338. [2017-08-16 11:45:39,570] (fs) DEBUG - RESPONSE: 610762 session(s) since startup
  339. [2017-08-16 11:45:39,570] (fs) DEBUG - RESPONSE: 882 session(s) - 0 out of max 150 per sec peak 9 (1 last 5min)
  340. [2017-08-16 11:45:39,570] (fs) DEBUG - RESPONSE: 2000 session(s) max
  341. [2017-08-16 11:45:39,570] (fs) DEBUG - RESPONSE: min idle cpu 0.00/28.00
  342. [2017-08-16 11:45:39,570] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  343. [2017-08-16 11:45:39,584] (fs) DEBUG - fsmainloop receiving message..
  344. [2017-08-16 11:45:39,627] (cluster) DEBUG - updating all information...
  345. [2017-08-16 11:45:39,627] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  346. [2017-08-16 11:45:39,670] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  347. [2017-08-16 11:45:39,698] (root) DEBUG - no events on inotify watcher
  348. [2017-08-16 11:45:39,699] (cluster) DEBUG - update cibmap called (force=False)
  349. [2017-08-16 11:45:39,700] (cluster) DEBUG - cib not changed, looping...
  350. [2017-08-16 11:45:41,584] (fs) DEBUG - timeout waiting for messages on queue
  351. [2017-08-16 11:45:41,585] (fs) DEBUG - fsmainloop receiving message..
  352. [2017-08-16 11:45:41,700] (cluster) DEBUG - updating all information...
  353. [2017-08-16 11:45:41,700] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  354. [2017-08-16 11:45:41,713] (db) DEBUG - creating new DB connection...
  355. [2017-08-16 11:45:41,723] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 24, 'stdout': 22})
  356. [2017-08-16 11:45:41,747] (db) DEBUG - users already verified..
  357. [2017-08-16 11:45:41,750] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  358. [2017-08-16 11:45:41,751] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  359. [2017-08-16 11:45:41,752] (db) DEBUG - closing DB connection...
  360. [2017-08-16 11:45:41,752] (db) DEBUG - mariadb status: running
  361. [2017-08-16 11:45:43,585] (fs) DEBUG - timeout waiting for messages on queue
  362. [2017-08-16 11:45:43,585] (fs) DEBUG - fsmainloop receiving message..
  363. [2017-08-16 11:45:45,404] (server) DEBUG - accepting new connection...
  364. [2017-08-16 11:45:45,406] (request) DEBUG - handling connection from ('127.0.0.1', 46040)
  365. [2017-08-16 11:45:45,406] (request) DEBUG - received request: ['STATUS']
  366. [2017-08-16 11:45:45,406] (request) DEBUG - querying status from led...
  367. [2017-08-16 11:45:45,406] (request) DEBUG - querying status from fs...
  368. [2017-08-16 11:45:45,406] (request) DEBUG - querying status from db...
  369. [2017-08-16 11:45:45,407] (request) DEBUG - querying status from mon...
  370. [2017-08-16 11:45:45,407] (request) DEBUG - querying status from cluster...
  371. [2017-08-16 11:45:45,585] (fs) DEBUG - timeout waiting for messages on queue
  372. [2017-08-16 11:45:45,586] (fs) DEBUG - fsmainloop receiving message..
  373. [2017-08-16 11:45:45,753] (db) DEBUG - creating new DB connection...
  374. [2017-08-16 11:45:45,755] (db) DEBUG - users already verified..
  375. [2017-08-16 11:45:45,755] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  376. [2017-08-16 11:45:45,757] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  377. [2017-08-16 11:45:45,758] (db) DEBUG - closing DB connection...
  378. [2017-08-16 11:45:45,758] (db) DEBUG - mariadb status: running
  379. [2017-08-16 11:45:47,586] (fs) DEBUG - timeout waiting for messages on queue
  380. [2017-08-16 11:45:47,586] (fs) DEBUG - fsmainloop receiving message..
  381. [2017-08-16 11:45:49,586] (fs) DEBUG - timeout waiting for messages on queue
  382. [2017-08-16 11:45:49,587] (fs) DEBUG - fsmainloop receiving message..
  383. [2017-08-16 11:45:49,759] (db) DEBUG - creating new DB connection...
  384. [2017-08-16 11:45:49,760] (db) DEBUG - users already verified..
  385. [2017-08-16 11:45:49,760] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  386. [2017-08-16 11:45:49,761] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  387. [2017-08-16 11:45:49,762] (db) DEBUG - closing DB connection...
  388. [2017-08-16 11:45:49,762] (db) DEBUG - mariadb status: running
  389. [2017-08-16 11:45:51,587] (fs) DEBUG - timeout waiting for messages on queue
  390. [2017-08-16 11:45:51,587] (fs) DEBUG - fsmainloop receiving message..
  391. [2017-08-16 11:45:53,587] (fs) DEBUG - timeout waiting for messages on queue
  392. [2017-08-16 11:45:53,587] (fs) DEBUG - fsmainloop receiving message..
  393. [2017-08-16 11:45:53,763] (db) DEBUG - creating new DB connection...
  394. [2017-08-16 11:45:53,764] (db) DEBUG - users already verified..
  395. [2017-08-16 11:45:53,765] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  396. [2017-08-16 11:45:53,765] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  397. [2017-08-16 11:45:53,766] (db) DEBUG - closing DB connection...
  398. [2017-08-16 11:45:53,766] (db) DEBUG - mariadb status: running
  399. [2017-08-16 11:45:55,588] (fs) DEBUG - timeout waiting for messages on queue
  400. [2017-08-16 11:45:55,588] (fs) DEBUG - fsmainloop - pinging...
  401. [2017-08-16 11:45:55,588] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  402. [2017-08-16 11:45:55,588] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  403. [2017-08-16 11:45:55,589] (fs) DEBUG - Connection driver esl loaded
  404. [2017-08-16 11:45:55,589] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  405. [2017-08-16 11:45:55,589] (fs) DEBUG - Initialized base connection
  406. [2017-08-16 11:45:55,589] (fs) DEBUG - Connection driver esl created
  407. [2017-08-16 11:45:55,590] (fs) DEBUG - check_connection()
  408. [2017-08-16 11:45:55,590] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  409. [2017-08-16 11:45:55,594] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  410. [2017-08-16 11:45:55,594] (fs) DEBUG - check_event(timeout=1)
  411. [2017-08-16 11:45:55,595] (fs) DEBUG - sending status message to FS...
  412. [2017-08-16 11:45:55,596] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  413. [2017-08-16 11:45:55,596] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  414. [2017-08-16 11:45:55,596] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3a1f090>: ['BACKGROUND_JOB']
  415. [2017-08-16 11:45:55,597] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  416. [2017-08-16 11:45:55,599] (fs) DEBUG - waiting event on FS...
  417. [2017-08-16 11:45:55,599] (fs) DEBUG - check_event(timeout=30000)
  418. [2017-08-16 11:45:55,599] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  419. [2017-08-16 11:45:55,600] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 43 minutes, 3 seconds, 629 milliseconds, 394 microseconds
  420. [2017-08-16 11:45:55,600] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  421. [2017-08-16 11:45:55,600] (fs) DEBUG - RESPONSE: 610842 session(s) since startup
  422. [2017-08-16 11:45:55,600] (fs) DEBUG - RESPONSE: 898 session(s) - 1 out of max 150 per sec peak 9 (4 last 5min)
  423. [2017-08-16 11:45:55,600] (fs) DEBUG - RESPONSE: 2000 session(s) max
  424. [2017-08-16 11:45:55,600] (fs) DEBUG - RESPONSE: min idle cpu 0.00/79.00
  425. [2017-08-16 11:45:55,600] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  426. [2017-08-16 11:45:55,605] (fs) DEBUG - fsmainloop receiving message..
  427. [2017-08-16 11:45:57,511] (server) DEBUG - accepting new connection...
  428. [2017-08-16 11:45:57,511] (request) DEBUG - handling connection from ('127.0.0.1', 46072)
  429. [2017-08-16 11:45:57,511] (request) DEBUG - received request: ['PING']
  430. [2017-08-16 11:45:57,512] (request) DEBUG - sending ping to cluster thread...
  431. [2017-08-16 11:45:57,512] (root) DEBUG - adding {'request': 'ping'} to message Message()
  432. [2017-08-16 11:45:57,512] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x36b18c0>} to message Message(request=ping)
  433. [2017-08-16 11:45:57,512] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x36b18c0>, 'request': 'ping', 'target': 'cluster'} to message Message()
  434. [2017-08-16 11:45:57,512] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x36b18c0>, target=cluster)" to "cluster"...
  435. [2017-08-16 11:45:57,605] (fs) DEBUG - timeout waiting for messages on queue
  436. [2017-08-16 11:45:57,605] (fs) DEBUG - fsmainloop receiving message..
  437. [2017-08-16 11:45:57,767] (db) DEBUG - creating new DB connection...
  438. [2017-08-16 11:45:57,768] (db) DEBUG - users already verified..
  439. [2017-08-16 11:45:57,768] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  440. [2017-08-16 11:45:57,769] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  441. [2017-08-16 11:45:57,770] (db) DEBUG - closing DB connection...
  442. [2017-08-16 11:45:57,770] (db) DEBUG - mariadb status: running
  443. [2017-08-16 11:45:59,606] (fs) DEBUG - timeout waiting for messages on queue
  444. [2017-08-16 11:45:59,606] (fs) DEBUG - fsmainloop receiving message..
  445. [2017-08-16 11:46:01,606] (fs) DEBUG - timeout waiting for messages on queue
  446. [2017-08-16 11:46:01,606] (fs) DEBUG - fsmainloop receiving message..
  447. [2017-08-16 11:46:01,770] (db) DEBUG - creating new DB connection...
  448. [2017-08-16 11:46:01,772] (db) DEBUG - users already verified..
  449. [2017-08-16 11:46:01,772] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  450. [2017-08-16 11:46:01,773] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  451. [2017-08-16 11:46:01,774] (db) DEBUG - closing DB connection...
  452. [2017-08-16 11:46:01,774] (db) DEBUG - mariadb status: running
  453. [2017-08-16 11:46:03,606] (fs) DEBUG - timeout waiting for messages on queue
  454. [2017-08-16 11:46:03,607] (fs) DEBUG - fsmainloop receiving message..
  455. [2017-08-16 11:46:05,448] (server) DEBUG - accepting new connection...
  456. [2017-08-16 11:46:05,449] (request) DEBUG - handling connection from ('127.0.0.1', 46088)
  457. [2017-08-16 11:46:05,449] (request) DEBUG - received request: ['STATUS']
  458. [2017-08-16 11:46:05,449] (request) DEBUG - querying status from led...
  459. [2017-08-16 11:46:05,449] (request) DEBUG - querying status from fs...
  460. [2017-08-16 11:46:05,449] (request) DEBUG - querying status from db...
  461. [2017-08-16 11:46:05,450] (request) DEBUG - querying status from mon...
  462. [2017-08-16 11:46:05,450] (request) DEBUG - querying status from cluster...
  463. [2017-08-16 11:46:05,607] (fs) DEBUG - timeout waiting for messages on queue
  464. [2017-08-16 11:46:05,607] (fs) DEBUG - fsmainloop receiving message..
  465. [2017-08-16 11:46:05,774] (db) DEBUG - creating new DB connection...
  466. [2017-08-16 11:46:05,777] (db) DEBUG - users already verified..
  467. [2017-08-16 11:46:05,777] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  468. [2017-08-16 11:46:05,778] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  469. [2017-08-16 11:46:05,779] (db) DEBUG - closing DB connection...
  470. [2017-08-16 11:46:05,779] (db) DEBUG - mariadb status: running
  471. [2017-08-16 11:46:07,607] (fs) DEBUG - timeout waiting for messages on queue
  472. [2017-08-16 11:46:07,607] (fs) DEBUG - fsmainloop receiving message..
  473. [2017-08-16 11:46:09,608] (fs) DEBUG - timeout waiting for messages on queue
  474. [2017-08-16 11:46:09,608] (fs) DEBUG - fsmainloop receiving message..
  475. [2017-08-16 11:46:09,780] (db) DEBUG - creating new DB connection...
  476. [2017-08-16 11:46:09,781] (db) DEBUG - users already verified..
  477. [2017-08-16 11:46:09,781] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  478. [2017-08-16 11:46:09,782] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  479. [2017-08-16 11:46:09,782] (db) DEBUG - closing DB connection...
  480. [2017-08-16 11:46:09,783] (db) DEBUG - mariadb status: running
  481. [2017-08-16 11:46:11,608] (fs) DEBUG - timeout waiting for messages on queue
  482. [2017-08-16 11:46:11,608] (fs) DEBUG - fsmainloop - pinging...
  483. [2017-08-16 11:46:11,609] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  484. [2017-08-16 11:46:11,609] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  485. [2017-08-16 11:46:11,609] (fs) DEBUG - Connection driver esl loaded
  486. [2017-08-16 11:46:11,609] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  487. [2017-08-16 11:46:11,609] (fs) DEBUG - Initialized base connection
  488. [2017-08-16 11:46:11,609] (fs) DEBUG - Connection driver esl created
  489. [2017-08-16 11:46:11,610] (fs) DEBUG - check_connection()
  490. [2017-08-16 11:46:11,610] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  491. [2017-08-16 11:46:11,614] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  492. [2017-08-16 11:46:11,614] (fs) DEBUG - check_event(timeout=1)
  493. [2017-08-16 11:46:11,615] (fs) DEBUG - sending status message to FS...
  494. [2017-08-16 11:46:11,615] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  495. [2017-08-16 11:46:11,615] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  496. [2017-08-16 11:46:11,615] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x39f2c90>: ['BACKGROUND_JOB']
  497. [2017-08-16 11:46:11,617] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  498. [2017-08-16 11:46:11,619] (fs) DEBUG - waiting event on FS...
  499. [2017-08-16 11:46:11,619] (fs) DEBUG - check_event(timeout=30000)
  500. [2017-08-16 11:46:11,619] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  501. [2017-08-16 11:46:11,619] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 43 minutes, 19 seconds, 649 milliseconds, 364 microseconds
  502. [2017-08-16 11:46:11,619] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  503. [2017-08-16 11:46:11,619] (fs) DEBUG - RESPONSE: 610892 session(s) since startup
  504. [2017-08-16 11:46:11,619] (fs) DEBUG - RESPONSE: 892 session(s) - 0 out of max 150 per sec peak 9 (2 last 5min)
  505. [2017-08-16 11:46:11,619] (fs) DEBUG - RESPONSE: 2000 session(s) max
  506. [2017-08-16 11:46:11,619] (fs) DEBUG - RESPONSE: min idle cpu 0.00/90.00
  507. [2017-08-16 11:46:11,619] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  508. [2017-08-16 11:46:11,625] (fs) DEBUG - fsmainloop receiving message..
  509. [2017-08-16 11:46:12,512] (server) DEBUG - accepting new connection...
  510. [2017-08-16 11:46:12,512] (request) DEBUG - handling connection from ('127.0.0.1', 46118)
  511. [2017-08-16 11:46:12,512] (request) DEBUG - received request: ['PING']
  512. [2017-08-16 11:46:12,512] (request) DEBUG - sending ping to cluster thread...
  513. [2017-08-16 11:46:12,512] (root) DEBUG - adding {'request': 'ping'} to message Message()
  514. [2017-08-16 11:46:12,513] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x3ad3fc8>} to message Message(request=ping)
  515. [2017-08-16 11:46:12,513] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x3ad3fc8>, 'request': 'ping', 'target': 'cluster'} to message Message()
  516. [2017-08-16 11:46:12,513] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x3ad3fc8>, target=cluster)" to "cluster"...
  517. [2017-08-16 11:46:13,626] (fs) DEBUG - timeout waiting for messages on queue
  518. [2017-08-16 11:46:13,626] (fs) DEBUG - fsmainloop receiving message..
  519. [2017-08-16 11:46:13,783] (db) DEBUG - creating new DB connection...
  520. [2017-08-16 11:46:13,784] (db) DEBUG - users already verified..
  521. [2017-08-16 11:46:13,785] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  522. [2017-08-16 11:46:13,785] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  523. [2017-08-16 11:46:13,786] (db) DEBUG - closing DB connection...
  524. [2017-08-16 11:46:13,786] (db) DEBUG - mariadb status: running
  525. [2017-08-16 11:46:15,626] (fs) DEBUG - timeout waiting for messages on queue
  526. [2017-08-16 11:46:15,626] (fs) DEBUG - fsmainloop receiving message..
  527. [2017-08-16 11:46:17,627] (fs) DEBUG - timeout waiting for messages on queue
  528. [2017-08-16 11:46:17,627] (fs) DEBUG - fsmainloop receiving message..
  529. [2017-08-16 11:46:17,786] (db) DEBUG - creating new DB connection...
  530. [2017-08-16 11:46:17,788] (db) DEBUG - users already verified..
  531. [2017-08-16 11:46:17,788] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  532. [2017-08-16 11:46:17,789] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  533. [2017-08-16 11:46:17,790] (db) DEBUG - closing DB connection...
  534. [2017-08-16 11:46:17,790] (db) DEBUG - mariadb status: running
  535. [2017-08-16 11:46:19,627] (fs) DEBUG - timeout waiting for messages on queue
  536. [2017-08-16 11:46:19,627] (fs) DEBUG - fsmainloop receiving message..
  537. [2017-08-16 11:46:21,628] (fs) DEBUG - timeout waiting for messages on queue
  538. [2017-08-16 11:46:21,628] (fs) DEBUG - fsmainloop receiving message..
  539. [2017-08-16 11:46:21,790] (db) DEBUG - creating new DB connection...
  540. [2017-08-16 11:46:21,792] (db) DEBUG - users already verified..
  541. [2017-08-16 11:46:21,792] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  542. [2017-08-16 11:46:21,793] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  543. [2017-08-16 11:46:21,793] (db) DEBUG - closing DB connection...
  544. [2017-08-16 11:46:21,793] (db) DEBUG - mariadb status: running
  545. [2017-08-16 11:46:23,628] (fs) DEBUG - timeout waiting for messages on queue
  546. [2017-08-16 11:46:23,628] (fs) DEBUG - fsmainloop receiving message..
  547. [2017-08-16 11:46:25,500] (server) DEBUG - accepting new connection...
  548. [2017-08-16 11:46:25,500] (request) DEBUG - handling connection from ('127.0.0.1', 46134)
  549. [2017-08-16 11:46:25,500] (request) DEBUG - received request: ['STATUS']
  550. [2017-08-16 11:46:25,501] (request) DEBUG - querying status from led...
  551. [2017-08-16 11:46:25,501] (request) DEBUG - querying status from fs...
  552. [2017-08-16 11:46:25,501] (request) DEBUG - querying status from db...
  553. [2017-08-16 11:46:25,501] (request) DEBUG - querying status from mon...
  554. [2017-08-16 11:46:25,501] (request) DEBUG - querying status from cluster...
  555. [2017-08-16 11:46:25,628] (fs) DEBUG - timeout waiting for messages on queue
  556. [2017-08-16 11:46:25,629] (fs) DEBUG - fsmainloop receiving message..
  557. [2017-08-16 11:46:25,794] (db) DEBUG - creating new DB connection...
  558. [2017-08-16 11:46:25,796] (db) DEBUG - users already verified..
  559. [2017-08-16 11:46:25,796] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  560. [2017-08-16 11:46:25,797] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  561. [2017-08-16 11:46:25,798] (db) DEBUG - closing DB connection...
  562. [2017-08-16 11:46:25,798] (db) DEBUG - mariadb status: running
  563. [2017-08-16 11:46:27,513] (server) DEBUG - accepting new connection...
  564. [2017-08-16 11:46:27,513] (request) DEBUG - handling connection from ('127.0.0.1', 46138)
  565. [2017-08-16 11:46:27,513] (request) DEBUG - received request: ['PING']
  566. [2017-08-16 11:46:27,513] (request) DEBUG - sending ping to cluster thread...
  567. [2017-08-16 11:46:27,514] (root) DEBUG - adding {'request': 'ping'} to message Message()
  568. [2017-08-16 11:46:27,514] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d9a830>} to message Message(request=ping)
  569. [2017-08-16 11:46:27,514] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d9a830>, 'request': 'ping', 'target': 'cluster'} to message Message()
  570. [2017-08-16 11:46:27,514] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x2d9a830>, target=cluster)" to "cluster"...
  571. [2017-08-16 11:46:27,629] (fs) DEBUG - timeout waiting for messages on queue
  572. [2017-08-16 11:46:27,629] (fs) DEBUG - fsmainloop - pinging...
  573. [2017-08-16 11:46:27,629] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  574. [2017-08-16 11:46:27,629] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  575. [2017-08-16 11:46:27,630] (fs) DEBUG - Connection driver esl loaded
  576. [2017-08-16 11:46:27,630] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  577. [2017-08-16 11:46:27,630] (fs) DEBUG - Initialized base connection
  578. [2017-08-16 11:46:27,630] (fs) DEBUG - Connection driver esl created
  579. [2017-08-16 11:46:27,630] (fs) DEBUG - check_connection()
  580. [2017-08-16 11:46:27,631] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  581. [2017-08-16 11:46:27,637] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  582. [2017-08-16 11:46:27,637] (fs) DEBUG - check_event(timeout=1)
  583. [2017-08-16 11:46:27,638] (fs) DEBUG - sending status message to FS...
  584. [2017-08-16 11:46:27,639] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  585. [2017-08-16 11:46:27,639] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  586. [2017-08-16 11:46:27,639] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3a14490>: ['BACKGROUND_JOB']
  587. [2017-08-16 11:46:27,640] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  588. [2017-08-16 11:46:27,642] (fs) DEBUG - waiting event on FS...
  589. [2017-08-16 11:46:27,642] (fs) DEBUG - check_event(timeout=30000)
  590. [2017-08-16 11:46:27,642] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  591. [2017-08-16 11:46:27,642] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 43 minutes, 35 seconds, 669 milliseconds, 370 microseconds
  592. [2017-08-16 11:46:27,642] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  593. [2017-08-16 11:46:27,642] (fs) DEBUG - RESPONSE: 610952 session(s) since startup
  594. [2017-08-16 11:46:27,642] (fs) DEBUG - RESPONSE: 882 session(s) - 1 out of max 150 per sec peak 9 (4 last 5min)
  595. [2017-08-16 11:46:27,642] (fs) DEBUG - RESPONSE: 2000 session(s) max
  596. [2017-08-16 11:46:27,643] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  597. [2017-08-16 11:46:27,643] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  598. [2017-08-16 11:46:27,646] (fs) DEBUG - fsmainloop receiving message..
  599. [2017-08-16 11:46:29,646] (fs) DEBUG - timeout waiting for messages on queue
  600. [2017-08-16 11:46:29,646] (fs) DEBUG - fsmainloop receiving message..
  601. [2017-08-16 11:46:29,799] (db) DEBUG - creating new DB connection...
  602. [2017-08-16 11:46:29,800] (db) DEBUG - users already verified..
  603. [2017-08-16 11:46:29,800] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  604. [2017-08-16 11:46:29,801] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  605. [2017-08-16 11:46:29,802] (db) DEBUG - closing DB connection...
  606. [2017-08-16 11:46:29,802] (db) DEBUG - mariadb status: running
  607. [2017-08-16 11:46:31,647] (fs) DEBUG - timeout waiting for messages on queue
  608. [2017-08-16 11:46:31,647] (fs) DEBUG - fsmainloop receiving message..
  609. [2017-08-16 11:46:32,512] (request) DEBUG - got response from ping: False...
  610. [2017-08-16 11:46:33,647] (fs) DEBUG - timeout waiting for messages on queue
  611. [2017-08-16 11:46:33,647] (fs) DEBUG - fsmainloop receiving message..
  612. [2017-08-16 11:46:33,802] (db) DEBUG - creating new DB connection...
  613. [2017-08-16 11:46:33,803] (db) DEBUG - users already verified..
  614. [2017-08-16 11:46:33,804] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  615. [2017-08-16 11:46:33,804] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  616. [2017-08-16 11:46:33,805] (db) DEBUG - closing DB connection...
  617. [2017-08-16 11:46:33,805] (db) DEBUG - mariadb status: running
  618. [2017-08-16 11:46:35,648] (fs) DEBUG - timeout waiting for messages on queue
  619. [2017-08-16 11:46:35,648] (fs) DEBUG - fsmainloop receiving message..
  620. [2017-08-16 11:46:37,648] (fs) DEBUG - timeout waiting for messages on queue
  621. [2017-08-16 11:46:37,648] (fs) DEBUG - fsmainloop receiving message..
  622. [2017-08-16 11:46:37,806] (db) DEBUG - creating new DB connection...
  623. [2017-08-16 11:46:37,807] (db) DEBUG - users already verified..
  624. [2017-08-16 11:46:37,807] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  625. [2017-08-16 11:46:37,809] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  626. [2017-08-16 11:46:37,809] (db) DEBUG - closing DB connection...
  627. [2017-08-16 11:46:37,809] (db) DEBUG - mariadb status: running
  628. [2017-08-16 11:46:39,648] (fs) DEBUG - timeout waiting for messages on queue
  629. [2017-08-16 11:46:39,649] (fs) DEBUG - fsmainloop receiving message..
  630. [2017-08-16 11:46:41,649] (fs) DEBUG - timeout waiting for messages on queue
  631. [2017-08-16 11:46:41,649] (fs) DEBUG - fsmainloop receiving message..
  632. [2017-08-16 11:46:41,810] (db) DEBUG - creating new DB connection...
  633. [2017-08-16 11:46:41,811] (db) DEBUG - users already verified..
  634. [2017-08-16 11:46:41,811] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  635. [2017-08-16 11:46:41,812] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  636. [2017-08-16 11:46:41,813] (db) DEBUG - closing DB connection...
  637. [2017-08-16 11:46:41,813] (db) DEBUG - mariadb status: running
  638. [2017-08-16 11:46:43,649] (fs) DEBUG - timeout waiting for messages on queue
  639. [2017-08-16 11:46:43,650] (fs) DEBUG - fsmainloop - pinging...
  640. [2017-08-16 11:46:43,650] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  641. [2017-08-16 11:46:43,650] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  642. [2017-08-16 11:46:43,650] (fs) DEBUG - Connection driver esl loaded
  643. [2017-08-16 11:46:43,651] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  644. [2017-08-16 11:46:43,651] (fs) DEBUG - Initialized base connection
  645. [2017-08-16 11:46:43,651] (fs) DEBUG - Connection driver esl created
  646. [2017-08-16 11:46:43,651] (fs) DEBUG - check_connection()
  647. [2017-08-16 11:46:43,651] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  648. [2017-08-16 11:46:43,657] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  649. [2017-08-16 11:46:43,657] (fs) DEBUG - check_event(timeout=1)
  650. [2017-08-16 11:46:43,658] (fs) DEBUG - sending status message to FS...
  651. [2017-08-16 11:46:43,658] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  652. [2017-08-16 11:46:43,658] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  653. [2017-08-16 11:46:43,658] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3a14310>: ['BACKGROUND_JOB']
  654. [2017-08-16 11:46:43,659] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  655. [2017-08-16 11:46:43,661] (fs) DEBUG - waiting event on FS...
  656. [2017-08-16 11:46:43,661] (fs) DEBUG - check_event(timeout=30000)
  657. [2017-08-16 11:46:43,661] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  658. [2017-08-16 11:46:43,661] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 43 minutes, 51 seconds, 689 milliseconds, 365 microseconds
  659. [2017-08-16 11:46:43,661] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  660. [2017-08-16 11:46:43,661] (fs) DEBUG - RESPONSE: 611002 session(s) since startup
  661. [2017-08-16 11:46:43,661] (fs) DEBUG - RESPONSE: 860 session(s) - 3 out of max 150 per sec peak 9 (3 last 5min)
  662. [2017-08-16 11:46:43,661] (fs) DEBUG - RESPONSE: 2000 session(s) max
  663. [2017-08-16 11:46:43,661] (fs) DEBUG - RESPONSE: min idle cpu 0.00/92.00
  664. [2017-08-16 11:46:43,661] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  665. [2017-08-16 11:46:43,667] (fs) DEBUG - fsmainloop receiving message..
  666. [2017-08-16 11:46:45,667] (fs) DEBUG - timeout waiting for messages on queue
  667. [2017-08-16 11:46:45,667] (fs) DEBUG - fsmainloop receiving message..
  668. [2017-08-16 11:46:45,813] (db) DEBUG - creating new DB connection...
  669. [2017-08-16 11:46:45,816] (db) DEBUG - users already verified..
  670. [2017-08-16 11:46:45,816] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  671. [2017-08-16 11:46:45,818] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  672. [2017-08-16 11:46:45,819] (db) DEBUG - closing DB connection...
  673. [2017-08-16 11:46:45,819] (db) DEBUG - mariadb status: running
  674. [2017-08-16 11:46:45,829] (server) DEBUG - accepting new connection...
  675. [2017-08-16 11:46:45,829] (request) DEBUG - handling connection from ('127.0.0.1', 46156)
  676. [2017-08-16 11:46:45,829] (request) DEBUG - received request: ['STATUS']
  677. [2017-08-16 11:46:45,829] (request) DEBUG - querying status from led...
  678. [2017-08-16 11:46:45,829] (request) DEBUG - querying status from fs...
  679. [2017-08-16 11:46:45,829] (request) DEBUG - querying status from db...
  680. [2017-08-16 11:46:45,829] (request) DEBUG - querying status from mon...
  681. [2017-08-16 11:46:45,829] (request) DEBUG - querying status from cluster...
  682. [2017-08-16 11:46:46,144] (monit) DEBUG - retrieving events ({'minid': 140909})...
  683. [2017-08-16 11:46:46,380] (monit) INFO - verifying 2 new audit point events...
  684. [2017-08-16 11:46:47,513] (request) DEBUG - got response from ping: False...
  685. [2017-08-16 11:46:47,667] (fs) DEBUG - timeout waiting for messages on queue
  686. [2017-08-16 11:46:47,668] (fs) DEBUG - fsmainloop receiving message..
  687. [2017-08-16 11:46:49,668] (fs) DEBUG - timeout waiting for messages on queue
  688. [2017-08-16 11:46:49,668] (fs) DEBUG - fsmainloop receiving message..
  689. [2017-08-16 11:46:49,820] (db) DEBUG - creating new DB connection...
  690. [2017-08-16 11:46:49,821] (db) DEBUG - users already verified..
  691. [2017-08-16 11:46:49,821] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  692. [2017-08-16 11:46:49,822] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  693. [2017-08-16 11:46:49,823] (db) DEBUG - closing DB connection...
  694. [2017-08-16 11:46:49,823] (db) DEBUG - mariadb status: running
  695. [2017-08-16 11:46:51,668] (fs) DEBUG - timeout waiting for messages on queue
  696. [2017-08-16 11:46:51,669] (fs) DEBUG - fsmainloop receiving message..
  697. [2017-08-16 11:46:53,669] (fs) DEBUG - timeout waiting for messages on queue
  698. [2017-08-16 11:46:53,669] (fs) DEBUG - fsmainloop receiving message..
  699. [2017-08-16 11:46:53,824] (db) DEBUG - creating new DB connection...
  700. [2017-08-16 11:46:53,825] (db) DEBUG - users already verified..
  701. [2017-08-16 11:46:53,825] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  702. [2017-08-16 11:46:53,826] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  703. [2017-08-16 11:46:53,826] (db) DEBUG - closing DB connection...
  704. [2017-08-16 11:46:53,827] (db) DEBUG - mariadb status: running
  705. [2017-08-16 11:46:55,669] (fs) DEBUG - timeout waiting for messages on queue
  706. [2017-08-16 11:46:55,669] (fs) DEBUG - fsmainloop receiving message..
  707. [2017-08-16 11:46:57,514] (server) DEBUG - accepting new connection...
  708. [2017-08-16 11:46:57,515] (request) DEBUG - handling connection from ('127.0.0.1', 46164)
  709. [2017-08-16 11:46:57,515] (request) DEBUG - received request: ['PING']
  710. [2017-08-16 11:46:57,515] (request) DEBUG - sending ping to cluster thread...
  711. [2017-08-16 11:46:57,516] (root) DEBUG - adding {'request': 'ping'} to message Message()
  712. [2017-08-16 11:46:57,516] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d2ec68>} to message Message(request=ping)
  713. [2017-08-16 11:46:57,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d2ec68>, 'request': 'ping', 'target': 'cluster'} to message Message()
  714. [2017-08-16 11:46:57,517] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x2d2ec68>, target=cluster)" to "cluster"...
  715. [2017-08-16 11:46:57,670] (fs) DEBUG - timeout waiting for messages on queue
  716. [2017-08-16 11:46:57,670] (fs) DEBUG - fsmainloop receiving message..
  717. [2017-08-16 11:46:57,827] (db) DEBUG - creating new DB connection...
  718. [2017-08-16 11:46:57,828] (db) DEBUG - users already verified..
  719. [2017-08-16 11:46:57,828] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  720. [2017-08-16 11:46:57,829] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  721. [2017-08-16 11:46:57,830] (db) DEBUG - closing DB connection...
  722. [2017-08-16 11:46:57,830] (db) DEBUG - mariadb status: running
  723. [2017-08-16 11:46:59,670] (fs) DEBUG - timeout waiting for messages on queue
  724. [2017-08-16 11:46:59,670] (fs) DEBUG - fsmainloop - pinging...
  725. [2017-08-16 11:46:59,671] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  726. [2017-08-16 11:46:59,671] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  727. [2017-08-16 11:46:59,671] (fs) DEBUG - Connection driver esl loaded
  728. [2017-08-16 11:46:59,671] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  729. [2017-08-16 11:46:59,671] (fs) DEBUG - Initialized base connection
  730. [2017-08-16 11:46:59,671] (fs) DEBUG - Connection driver esl created
  731. [2017-08-16 11:46:59,672] (fs) DEBUG - check_connection()
  732. [2017-08-16 11:46:59,672] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  733. [2017-08-16 11:46:59,676] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  734. [2017-08-16 11:46:59,676] (fs) DEBUG - check_event(timeout=1)
  735. [2017-08-16 11:46:59,677] (fs) DEBUG - sending status message to FS...
  736. [2017-08-16 11:46:59,677] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  737. [2017-08-16 11:46:59,677] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  738. [2017-08-16 11:46:59,677] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x39f2650>: ['BACKGROUND_JOB']
  739. [2017-08-16 11:46:59,678] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  740. [2017-08-16 11:46:59,680] (fs) DEBUG - waiting event on FS...
  741. [2017-08-16 11:46:59,680] (fs) DEBUG - check_event(timeout=30000)
  742. [2017-08-16 11:46:59,680] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  743. [2017-08-16 11:46:59,680] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 44 minutes, 7 seconds, 709 milliseconds, 391 microseconds
  744. [2017-08-16 11:46:59,680] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  745. [2017-08-16 11:46:59,680] (fs) DEBUG - RESPONSE: 611072 session(s) since startup
  746. [2017-08-16 11:46:59,680] (fs) DEBUG - RESPONSE: 874 session(s) - 0 out of max 150 per sec peak 9 (4 last 5min)
  747. [2017-08-16 11:46:59,680] (fs) DEBUG - RESPONSE: 2000 session(s) max
  748. [2017-08-16 11:46:59,681] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  749. [2017-08-16 11:46:59,681] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  750. [2017-08-16 11:46:59,687] (fs) DEBUG - fsmainloop receiving message..
  751. [2017-08-16 11:47:01,687] (fs) DEBUG - timeout waiting for messages on queue
  752. [2017-08-16 11:47:01,687] (fs) DEBUG - fsmainloop receiving message..
  753. [2017-08-16 11:47:01,830] (db) DEBUG - creating new DB connection...
  754. [2017-08-16 11:47:01,832] (db) DEBUG - users already verified..
  755. [2017-08-16 11:47:01,832] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  756. [2017-08-16 11:47:01,833] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  757. [2017-08-16 11:47:01,834] (db) DEBUG - closing DB connection...
  758. [2017-08-16 11:47:01,834] (db) DEBUG - mariadb status: running
  759. [2017-08-16 11:47:02,514] (request) DEBUG - got response from ping: False...
  760. [2017-08-16 11:47:03,688] (fs) DEBUG - timeout waiting for messages on queue
  761. [2017-08-16 11:47:03,688] (fs) DEBUG - fsmainloop receiving message..
  762. [2017-08-16 11:47:05,688] (fs) DEBUG - timeout waiting for messages on queue
  763. [2017-08-16 11:47:05,688] (fs) DEBUG - fsmainloop receiving message..
  764. [2017-08-16 11:47:05,835] (db) DEBUG - creating new DB connection...
  765. [2017-08-16 11:47:05,837] (db) DEBUG - users already verified..
  766. [2017-08-16 11:47:05,838] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  767. [2017-08-16 11:47:05,839] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  768. [2017-08-16 11:47:05,839] (db) DEBUG - closing DB connection...
  769. [2017-08-16 11:47:05,840] (db) DEBUG - mariadb status: running
  770. [2017-08-16 11:47:06,471] (server) DEBUG - accepting new connection...
  771. [2017-08-16 11:47:06,472] (request) DEBUG - handling connection from ('127.0.0.1', 46180)
  772. [2017-08-16 11:47:06,472] (request) DEBUG - received request: ['STATUS']
  773. [2017-08-16 11:47:06,472] (request) DEBUG - querying status from led...
  774. [2017-08-16 11:47:06,472] (request) DEBUG - querying status from fs...
  775. [2017-08-16 11:47:06,472] (request) DEBUG - querying status from db...
  776. [2017-08-16 11:47:06,472] (request) DEBUG - querying status from mon...
  777. [2017-08-16 11:47:06,472] (request) DEBUG - querying status from cluster...
  778. [2017-08-16 11:47:07,689] (fs) DEBUG - timeout waiting for messages on queue
  779. [2017-08-16 11:47:07,689] (fs) DEBUG - fsmainloop receiving message..
  780. [2017-08-16 11:47:09,689] (fs) DEBUG - timeout waiting for messages on queue
  781. [2017-08-16 11:47:09,689] (fs) DEBUG - fsmainloop receiving message..
  782. [2017-08-16 11:47:09,840] (db) DEBUG - creating new DB connection...
  783. [2017-08-16 11:47:09,841] (db) DEBUG - users already verified..
  784. [2017-08-16 11:47:09,842] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  785. [2017-08-16 11:47:09,842] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  786. [2017-08-16 11:47:09,843] (db) DEBUG - closing DB connection...
  787. [2017-08-16 11:47:09,843] (db) DEBUG - mariadb status: running
  788. [2017-08-16 11:47:11,690] (fs) DEBUG - timeout waiting for messages on queue
  789. [2017-08-16 11:47:11,690] (fs) DEBUG - fsmainloop receiving message..
  790. [2017-08-16 11:47:12,515] (server) DEBUG - accepting new connection...
  791. [2017-08-16 11:47:12,515] (request) DEBUG - handling connection from ('127.0.0.1', 46182)
  792. [2017-08-16 11:47:12,516] (request) DEBUG - received request: ['PING']
  793. [2017-08-16 11:47:12,516] (request) DEBUG - sending ping to cluster thread...
  794. [2017-08-16 11:47:12,516] (root) DEBUG - adding {'request': 'ping'} to message Message()
  795. [2017-08-16 11:47:12,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x7fc5c08fdc68>} to message Message(request=ping)
  796. [2017-08-16 11:47:12,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x7fc5c08fdc68>, 'request': 'ping', 'target': 'cluster'} to message Message()
  797. [2017-08-16 11:47:12,517] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x7fc5c08fdc68>, target=cluster)" to "cluster"...
  798. [2017-08-16 11:47:13,690] (fs) DEBUG - timeout waiting for messages on queue
  799. [2017-08-16 11:47:13,690] (fs) DEBUG - fsmainloop receiving message..
  800. [2017-08-16 11:47:13,844] (db) DEBUG - creating new DB connection...
  801. [2017-08-16 11:47:13,845] (db) DEBUG - users already verified..
  802. [2017-08-16 11:47:13,845] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  803. [2017-08-16 11:47:13,846] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  804. [2017-08-16 11:47:13,847] (db) DEBUG - closing DB connection...
  805. [2017-08-16 11:47:13,847] (db) DEBUG - mariadb status: running
  806. [2017-08-16 11:47:15,690] (fs) DEBUG - timeout waiting for messages on queue
  807. [2017-08-16 11:47:15,691] (fs) DEBUG - fsmainloop - pinging...
  808. [2017-08-16 11:47:15,691] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  809. [2017-08-16 11:47:15,691] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  810. [2017-08-16 11:47:15,692] (fs) DEBUG - Connection driver esl loaded
  811. [2017-08-16 11:47:15,692] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  812. [2017-08-16 11:47:15,692] (fs) DEBUG - Initialized base connection
  813. [2017-08-16 11:47:15,692] (fs) DEBUG - Connection driver esl created
  814. [2017-08-16 11:47:15,692] (fs) DEBUG - check_connection()
  815. [2017-08-16 11:47:15,693] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  816. [2017-08-16 11:47:15,700] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  817. [2017-08-16 11:47:15,700] (fs) DEBUG - check_event(timeout=1)
  818. [2017-08-16 11:47:15,701] (fs) DEBUG - sending status message to FS...
  819. [2017-08-16 11:47:15,701] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  820. [2017-08-16 11:47:15,702] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  821. [2017-08-16 11:47:15,702] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3a14f50>: ['BACKGROUND_JOB']
  822. [2017-08-16 11:47:15,702] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  823. [2017-08-16 11:47:15,704] (fs) DEBUG - waiting event on FS...
  824. [2017-08-16 11:47:15,704] (fs) DEBUG - check_event(timeout=30000)
  825. [2017-08-16 11:47:15,704] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  826. [2017-08-16 11:47:15,704] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 44 minutes, 23 seconds, 729 milliseconds, 376 microseconds
  827. [2017-08-16 11:47:15,705] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  828. [2017-08-16 11:47:15,705] (fs) DEBUG - RESPONSE: 611144 session(s) since startup
  829. [2017-08-16 11:47:15,705] (fs) DEBUG - RESPONSE: 868 session(s) - 0 out of max 150 per sec peak 9 (4 last 5min)
  830. [2017-08-16 11:47:15,705] (fs) DEBUG - RESPONSE: 2000 session(s) max
  831. [2017-08-16 11:47:15,705] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  832. [2017-08-16 11:47:15,705] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  833. [2017-08-16 11:47:15,708] (fs) DEBUG - fsmainloop receiving message..
  834. [2017-08-16 11:47:17,708] (fs) DEBUG - timeout waiting for messages on queue
  835. [2017-08-16 11:47:17,708] (fs) DEBUG - fsmainloop receiving message..
  836. [2017-08-16 11:47:17,847] (db) DEBUG - creating new DB connection...
  837. [2017-08-16 11:47:17,849] (db) DEBUG - users already verified..
  838. [2017-08-16 11:47:17,849] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  839. [2017-08-16 11:47:17,850] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  840. [2017-08-16 11:47:17,850] (db) DEBUG - closing DB connection...
  841. [2017-08-16 11:47:17,850] (db) DEBUG - mariadb status: running
  842. [2017-08-16 11:47:19,709] (fs) DEBUG - timeout waiting for messages on queue
  843. [2017-08-16 11:47:19,709] (fs) DEBUG - fsmainloop receiving message..
  844. [2017-08-16 11:47:21,709] (fs) DEBUG - timeout waiting for messages on queue
  845. [2017-08-16 11:47:21,709] (fs) DEBUG - fsmainloop receiving message..
  846. [2017-08-16 11:47:21,851] (db) DEBUG - creating new DB connection...
  847. [2017-08-16 11:47:21,852] (db) DEBUG - users already verified..
  848. [2017-08-16 11:47:21,852] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  849. [2017-08-16 11:47:21,853] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  850. [2017-08-16 11:47:21,855] (db) DEBUG - closing DB connection...
  851. [2017-08-16 11:47:21,855] (db) DEBUG - mariadb status: running
  852. [2017-08-16 11:47:23,710] (fs) DEBUG - timeout waiting for messages on queue
  853. [2017-08-16 11:47:23,710] (fs) DEBUG - fsmainloop receiving message..
  854. [2017-08-16 11:47:25,710] (fs) DEBUG - timeout waiting for messages on queue
  855. [2017-08-16 11:47:25,710] (fs) DEBUG - fsmainloop receiving message..
  856. [2017-08-16 11:47:25,855] (db) DEBUG - creating new DB connection...
  857. [2017-08-16 11:47:25,857] (db) DEBUG - users already verified..
  858. [2017-08-16 11:47:25,857] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  859. [2017-08-16 11:47:25,858] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  860. [2017-08-16 11:47:25,859] (db) DEBUG - closing DB connection...
  861. [2017-08-16 11:47:25,859] (db) DEBUG - mariadb status: running
  862. [2017-08-16 11:47:26,808] (server) DEBUG - accepting new connection...
  863. [2017-08-16 11:47:26,808] (request) DEBUG - handling connection from ('127.0.0.1', 46188)
  864. [2017-08-16 11:47:26,808] (request) DEBUG - received request: ['STATUS']
  865. [2017-08-16 11:47:26,809] (request) DEBUG - querying status from led...
  866. [2017-08-16 11:47:26,809] (request) DEBUG - querying status from fs...
  867. [2017-08-16 11:47:26,809] (request) DEBUG - querying status from db...
  868. [2017-08-16 11:47:26,809] (request) DEBUG - querying status from mon...
  869. [2017-08-16 11:47:26,809] (request) DEBUG - querying status from cluster...
  870. [2017-08-16 11:47:27,516] (server) DEBUG - accepting new connection...
  871. [2017-08-16 11:47:27,516] (request) DEBUG - handling connection from ('127.0.0.1', 46196)
  872. [2017-08-16 11:47:27,516] (request) DEBUG - received request: ['PING']
  873. [2017-08-16 11:47:27,517] (request) DEBUG - sending ping to cluster thread...
  874. [2017-08-16 11:47:27,517] (root) DEBUG - adding {'request': 'ping'} to message Message()
  875. [2017-08-16 11:47:27,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d9a6c8>} to message Message(request=ping)
  876. [2017-08-16 11:47:27,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d9a6c8>, 'request': 'ping', 'target': 'cluster'} to message Message()
  877. [2017-08-16 11:47:27,517] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x2d9a6c8>, target=cluster)" to "cluster"...
  878. [2017-08-16 11:47:27,711] (fs) DEBUG - timeout waiting for messages on queue
  879. [2017-08-16 11:47:27,711] (fs) DEBUG - fsmainloop receiving message..
  880. [2017-08-16 11:47:29,711] (fs) DEBUG - timeout waiting for messages on queue
  881. [2017-08-16 11:47:29,711] (fs) DEBUG - fsmainloop receiving message..
  882. [2017-08-16 11:47:29,859] (db) DEBUG - creating new DB connection...
  883. [2017-08-16 11:47:29,861] (db) DEBUG - users already verified..
  884. [2017-08-16 11:47:29,861] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  885. [2017-08-16 11:47:29,862] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  886. [2017-08-16 11:47:29,862] (db) DEBUG - closing DB connection...
  887. [2017-08-16 11:47:29,863] (db) DEBUG - mariadb status: running
  888. [2017-08-16 11:47:31,711] (fs) DEBUG - timeout waiting for messages on queue
  889. [2017-08-16 11:47:31,712] (fs) DEBUG - fsmainloop - pinging...
  890. [2017-08-16 11:47:31,712] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  891. [2017-08-16 11:47:31,712] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  892. [2017-08-16 11:47:31,712] (fs) DEBUG - Connection driver esl loaded
  893. [2017-08-16 11:47:31,712] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  894. [2017-08-16 11:47:31,712] (fs) DEBUG - Initialized base connection
  895. [2017-08-16 11:47:31,713] (fs) DEBUG - Connection driver esl created
  896. [2017-08-16 11:47:31,713] (fs) DEBUG - check_connection()
  897. [2017-08-16 11:47:31,713] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  898. [2017-08-16 11:47:31,717] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  899. [2017-08-16 11:47:31,717] (fs) DEBUG - check_event(timeout=1)
  900. [2017-08-16 11:47:31,719] (fs) DEBUG - sending status message to FS...
  901. [2017-08-16 11:47:31,719] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  902. [2017-08-16 11:47:31,719] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  903. [2017-08-16 11:47:31,719] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3ae40d0>: ['BACKGROUND_JOB']
  904. [2017-08-16 11:47:31,719] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  905. [2017-08-16 11:47:31,721] (fs) DEBUG - waiting event on FS...
  906. [2017-08-16 11:47:31,721] (fs) DEBUG - check_event(timeout=30000)
  907. [2017-08-16 11:47:31,722] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  908. [2017-08-16 11:47:31,722] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 44 minutes, 39 seconds, 749 milliseconds, 365 microseconds
  909. [2017-08-16 11:47:31,722] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  910. [2017-08-16 11:47:31,722] (fs) DEBUG - RESPONSE: 611200 session(s) since startup
  911. [2017-08-16 11:47:31,722] (fs) DEBUG - RESPONSE: 870 session(s) - 0 out of max 150 per sec peak 9 (2 last 5min)
  912. [2017-08-16 11:47:31,722] (fs) DEBUG - RESPONSE: 2000 session(s) max
  913. [2017-08-16 11:47:31,722] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  914. [2017-08-16 11:47:31,722] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  915. [2017-08-16 11:47:31,728] (fs) DEBUG - fsmainloop receiving message..
  916. [2017-08-16 11:47:32,517] (request) DEBUG - got response from ping: False...
  917. [2017-08-16 11:47:33,729] (fs) DEBUG - timeout waiting for messages on queue
  918. [2017-08-16 11:47:33,729] (fs) DEBUG - fsmainloop receiving message..
  919. [2017-08-16 11:47:33,863] (db) DEBUG - creating new DB connection...
  920. [2017-08-16 11:47:33,865] (db) DEBUG - users already verified..
  921. [2017-08-16 11:47:33,865] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  922. [2017-08-16 11:47:33,865] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  923. [2017-08-16 11:47:33,866] (db) DEBUG - closing DB connection...
  924. [2017-08-16 11:47:33,866] (db) DEBUG - mariadb status: running
  925. [2017-08-16 11:47:35,729] (fs) DEBUG - timeout waiting for messages on queue
  926. [2017-08-16 11:47:35,729] (fs) DEBUG - fsmainloop receiving message..
  927. [2017-08-16 11:47:37,729] (fs) DEBUG - timeout waiting for messages on queue
  928. [2017-08-16 11:47:37,730] (fs) DEBUG - fsmainloop receiving message..
  929. [2017-08-16 11:47:37,867] (db) DEBUG - creating new DB connection...
  930. [2017-08-16 11:47:37,868] (db) DEBUG - users already verified..
  931. [2017-08-16 11:47:37,868] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  932. [2017-08-16 11:47:37,869] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  933. [2017-08-16 11:47:37,870] (db) DEBUG - closing DB connection...
  934. [2017-08-16 11:47:37,870] (db) DEBUG - mariadb status: running
  935. [2017-08-16 11:47:39,730] (fs) DEBUG - timeout waiting for messages on queue
  936. [2017-08-16 11:47:39,730] (fs) DEBUG - fsmainloop receiving message..
  937. [2017-08-16 11:47:41,730] (fs) DEBUG - timeout waiting for messages on queue
  938. [2017-08-16 11:47:41,731] (fs) DEBUG - fsmainloop receiving message..
  939. [2017-08-16 11:47:41,870] (db) DEBUG - creating new DB connection...
  940. [2017-08-16 11:47:41,872] (db) DEBUG - users already verified..
  941. [2017-08-16 11:47:41,872] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  942. [2017-08-16 11:47:41,873] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  943. [2017-08-16 11:47:41,873] (db) DEBUG - closing DB connection...
  944. [2017-08-16 11:47:41,874] (db) DEBUG - mariadb status: running
  945. [2017-08-16 11:47:43,731] (fs) DEBUG - timeout waiting for messages on queue
  946. [2017-08-16 11:47:43,731] (fs) DEBUG - fsmainloop receiving message..
  947. [2017-08-16 11:47:45,731] (fs) DEBUG - timeout waiting for messages on queue
  948. [2017-08-16 11:47:45,732] (fs) DEBUG - fsmainloop receiving message..
  949. [2017-08-16 11:47:45,874] (db) DEBUG - creating new DB connection...
  950. [2017-08-16 11:47:45,876] (db) DEBUG - users already verified..
  951. [2017-08-16 11:47:45,877] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  952. [2017-08-16 11:47:45,878] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  953. [2017-08-16 11:47:45,879] (db) DEBUG - closing DB connection...
  954. [2017-08-16 11:47:45,879] (db) DEBUG - mariadb status: running
  955. [2017-08-16 11:47:46,851] (server) DEBUG - accepting new connection...
  956. [2017-08-16 11:47:46,852] (request) DEBUG - handling connection from ('127.0.0.1', 46220)
  957. [2017-08-16 11:47:46,852] (request) DEBUG - received request: ['STATUS']
  958. [2017-08-16 11:47:46,852] (request) DEBUG - querying status from led...
  959. [2017-08-16 11:47:46,852] (request) DEBUG - querying status from fs...
  960. [2017-08-16 11:47:46,853] (request) DEBUG - querying status from db...
  961. [2017-08-16 11:47:46,853] (request) DEBUG - querying status from mon...
  962. [2017-08-16 11:47:46,853] (request) DEBUG - querying status from cluster...
  963. [2017-08-16 11:47:47,517] (request) DEBUG - got response from ping: False...
  964. [2017-08-16 11:47:47,732] (fs) DEBUG - timeout waiting for messages on queue
  965. [2017-08-16 11:47:47,732] (fs) DEBUG - fsmainloop - pinging...
  966. [2017-08-16 11:47:47,732] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  967. [2017-08-16 11:47:47,732] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  968. [2017-08-16 11:47:47,733] (fs) DEBUG - Connection driver esl loaded
  969. [2017-08-16 11:47:47,733] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  970. [2017-08-16 11:47:47,733] (fs) DEBUG - Initialized base connection
  971. [2017-08-16 11:47:47,733] (fs) DEBUG - Connection driver esl created
  972. [2017-08-16 11:47:47,733] (fs) DEBUG - check_connection()
  973. [2017-08-16 11:47:47,733] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  974. [2017-08-16 11:47:47,740] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  975. [2017-08-16 11:47:47,740] (fs) DEBUG - check_event(timeout=1)
  976. [2017-08-16 11:47:47,741] (fs) DEBUG - sending status message to FS...
  977. [2017-08-16 11:47:47,741] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  978. [2017-08-16 11:47:47,741] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  979. [2017-08-16 11:47:47,742] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3ae4150>: ['BACKGROUND_JOB']
  980. [2017-08-16 11:47:47,742] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  981. [2017-08-16 11:47:47,744] (fs) DEBUG - waiting event on FS...
  982. [2017-08-16 11:47:47,744] (fs) DEBUG - check_event(timeout=30000)
  983. [2017-08-16 11:47:47,744] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  984. [2017-08-16 11:47:47,744] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 44 minutes, 55 seconds, 769 milliseconds, 407 microseconds
  985. [2017-08-16 11:47:47,745] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  986. [2017-08-16 11:47:47,745] (fs) DEBUG - RESPONSE: 611264 session(s) since startup
  987. [2017-08-16 11:47:47,745] (fs) DEBUG - RESPONSE: 870 session(s) - 0 out of max 150 per sec peak 9 (3 last 5min)
  988. [2017-08-16 11:47:47,745] (fs) DEBUG - RESPONSE: 2000 session(s) max
  989. [2017-08-16 11:47:47,745] (fs) DEBUG - RESPONSE: min idle cpu 0.00/93.00
  990. [2017-08-16 11:47:47,745] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  991. [2017-08-16 11:47:47,749] (fs) DEBUG - fsmainloop receiving message..
  992. [2017-08-16 11:47:49,749] (fs) DEBUG - timeout waiting for messages on queue
  993. [2017-08-16 11:47:49,749] (fs) DEBUG - fsmainloop receiving message..
  994. [2017-08-16 11:47:49,879] (db) DEBUG - creating new DB connection...
  995. [2017-08-16 11:47:49,881] (db) DEBUG - users already verified..
  996. [2017-08-16 11:47:49,881] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  997. [2017-08-16 11:47:49,882] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  998. [2017-08-16 11:47:49,883] (db) DEBUG - closing DB connection...
  999. [2017-08-16 11:47:49,883] (db) DEBUG - mariadb status: running
  1000. [2017-08-16 11:47:51,749] (fs) DEBUG - timeout waiting for messages on queue
  1001. [2017-08-16 11:47:51,750] (fs) DEBUG - fsmainloop receiving message..
  1002. [2017-08-16 11:47:53,750] (fs) DEBUG - timeout waiting for messages on queue
  1003. [2017-08-16 11:47:53,750] (fs) DEBUG - fsmainloop receiving message..
  1004. [2017-08-16 11:47:53,883] (db) DEBUG - creating new DB connection...
  1005. [2017-08-16 11:47:53,885] (db) DEBUG - users already verified..
  1006. [2017-08-16 11:47:53,885] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1007. [2017-08-16 11:47:53,886] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1008. [2017-08-16 11:47:53,887] (db) DEBUG - closing DB connection...
  1009. [2017-08-16 11:47:53,887] (db) DEBUG - mariadb status: running
  1010. [2017-08-16 11:47:55,750] (fs) DEBUG - timeout waiting for messages on queue
  1011. [2017-08-16 11:47:55,751] (fs) DEBUG - fsmainloop receiving message..
  1012. [2017-08-16 11:47:57,514] (server) DEBUG - accepting new connection...
  1013. [2017-08-16 11:47:57,515] (request) DEBUG - handling connection from ('127.0.0.1', 46232)
  1014. [2017-08-16 11:47:57,515] (request) DEBUG - received request: ['PING']
  1015. [2017-08-16 11:47:57,515] (request) DEBUG - sending ping to cluster thread...
  1016. [2017-08-16 11:47:57,515] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1017. [2017-08-16 11:47:57,515] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x7fc5c08fddd0>} to message Message(request=ping)
  1018. [2017-08-16 11:47:57,515] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x7fc5c08fddd0>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1019. [2017-08-16 11:47:57,516] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x7fc5c08fddd0>, target=cluster)" to "cluster"...
  1020. [2017-08-16 11:47:57,751] (fs) DEBUG - timeout waiting for messages on queue
  1021. [2017-08-16 11:47:57,751] (fs) DEBUG - fsmainloop receiving message..
  1022. [2017-08-16 11:47:57,887] (db) DEBUG - creating new DB connection...
  1023. [2017-08-16 11:47:57,889] (db) DEBUG - users already verified..
  1024. [2017-08-16 11:47:57,889] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1025. [2017-08-16 11:47:57,890] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1026. [2017-08-16 11:47:57,890] (db) DEBUG - closing DB connection...
  1027. [2017-08-16 11:47:57,891] (db) DEBUG - mariadb status: running
  1028. [2017-08-16 11:47:59,751] (fs) DEBUG - timeout waiting for messages on queue
  1029. [2017-08-16 11:47:59,751] (fs) DEBUG - fsmainloop receiving message..
  1030. [2017-08-16 11:48:01,381] (monit) DEBUG - retrieving events ({'minid': 140911})...
  1031. [2017-08-16 11:48:01,610] (monit) INFO - verifying 2 new audit point events...
  1032. [2017-08-16 11:48:01,752] (fs) DEBUG - timeout waiting for messages on queue
  1033. [2017-08-16 11:48:01,752] (fs) DEBUG - fsmainloop receiving message..
  1034. [2017-08-16 11:48:01,891] (db) DEBUG - creating new DB connection...
  1035. [2017-08-16 11:48:01,892] (db) DEBUG - users already verified..
  1036. [2017-08-16 11:48:01,893] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1037. [2017-08-16 11:48:01,894] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1038. [2017-08-16 11:48:01,895] (db) DEBUG - closing DB connection...
  1039. [2017-08-16 11:48:01,895] (db) DEBUG - mariadb status: running
  1040. [2017-08-16 11:48:02,518] (request) DEBUG - got response from ping: False...
  1041. [2017-08-16 11:48:03,752] (fs) DEBUG - timeout waiting for messages on queue
  1042. [2017-08-16 11:48:03,752] (fs) DEBUG - fsmainloop - pinging...
  1043. [2017-08-16 11:48:03,752] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  1044. [2017-08-16 11:48:03,753] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  1045. [2017-08-16 11:48:03,753] (fs) DEBUG - Connection driver esl loaded
  1046. [2017-08-16 11:48:03,753] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  1047. [2017-08-16 11:48:03,753] (fs) DEBUG - Initialized base connection
  1048. [2017-08-16 11:48:03,753] (fs) DEBUG - Connection driver esl created
  1049. [2017-08-16 11:48:03,754] (fs) DEBUG - check_connection()
  1050. [2017-08-16 11:48:03,754] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  1051. [2017-08-16 11:48:03,760] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  1052. [2017-08-16 11:48:03,760] (fs) DEBUG - check_event(timeout=1)
  1053. [2017-08-16 11:48:03,761] (fs) DEBUG - sending status message to FS...
  1054. [2017-08-16 11:48:03,762] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  1055. [2017-08-16 11:48:03,762] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  1056. [2017-08-16 11:48:03,762] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3aa1590>: ['BACKGROUND_JOB']
  1057. [2017-08-16 11:48:03,762] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  1058. [2017-08-16 11:48:03,765] (fs) DEBUG - waiting event on FS...
  1059. [2017-08-16 11:48:03,765] (fs) DEBUG - check_event(timeout=30000)
  1060. [2017-08-16 11:48:03,765] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  1061. [2017-08-16 11:48:03,765] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 45 minutes, 11 seconds, 789 milliseconds, 394 microseconds
  1062. [2017-08-16 11:48:03,765] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  1063. [2017-08-16 11:48:03,765] (fs) DEBUG - RESPONSE: 611328 session(s) since startup
  1064. [2017-08-16 11:48:03,765] (fs) DEBUG - RESPONSE: 882 session(s) - 0 out of max 150 per sec peak 9 (2 last 5min)
  1065. [2017-08-16 11:48:03,765] (fs) DEBUG - RESPONSE: 2000 session(s) max
  1066. [2017-08-16 11:48:03,765] (fs) DEBUG - RESPONSE: min idle cpu 0.00/95.00
  1067. [2017-08-16 11:48:03,765] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  1068. [2017-08-16 11:48:03,769] (fs) DEBUG - fsmainloop receiving message..
  1069. [2017-08-16 11:48:05,770] (fs) DEBUG - timeout waiting for messages on queue
  1070. [2017-08-16 11:48:05,770] (fs) DEBUG - fsmainloop receiving message..
  1071. [2017-08-16 11:48:05,895] (db) DEBUG - creating new DB connection...
  1072. [2017-08-16 11:48:05,897] (db) DEBUG - users already verified..
  1073. [2017-08-16 11:48:05,897] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1074. [2017-08-16 11:48:05,898] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1075. [2017-08-16 11:48:05,899] (db) DEBUG - closing DB connection...
  1076. [2017-08-16 11:48:05,899] (db) DEBUG - mariadb status: running
  1077. [2017-08-16 11:48:06,894] (server) DEBUG - accepting new connection...
  1078. [2017-08-16 11:48:06,895] (request) DEBUG - handling connection from ('127.0.0.1', 46242)
  1079. [2017-08-16 11:48:06,895] (request) DEBUG - received request: ['STATUS']
  1080. [2017-08-16 11:48:06,895] (request) DEBUG - querying status from led...
  1081. [2017-08-16 11:48:06,895] (request) DEBUG - querying status from fs...
  1082. [2017-08-16 11:48:06,895] (request) DEBUG - querying status from db...
  1083. [2017-08-16 11:48:06,895] (request) DEBUG - querying status from mon...
  1084. [2017-08-16 11:48:06,895] (request) DEBUG - querying status from cluster...
  1085. [2017-08-16 11:48:07,770] (fs) DEBUG - timeout waiting for messages on queue
  1086. [2017-08-16 11:48:07,770] (fs) DEBUG - fsmainloop receiving message..
  1087. [2017-08-16 11:48:09,771] (fs) DEBUG - timeout waiting for messages on queue
  1088. [2017-08-16 11:48:09,771] (fs) DEBUG - fsmainloop receiving message..
  1089. [2017-08-16 11:48:09,900] (db) DEBUG - creating new DB connection...
  1090. [2017-08-16 11:48:09,901] (db) DEBUG - users already verified..
  1091. [2017-08-16 11:48:09,901] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1092. [2017-08-16 11:48:09,902] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1093. [2017-08-16 11:48:09,903] (db) DEBUG - closing DB connection...
  1094. [2017-08-16 11:48:09,903] (db) DEBUG - mariadb status: running
  1095. [2017-08-16 11:48:11,771] (fs) DEBUG - timeout waiting for messages on queue
  1096. [2017-08-16 11:48:11,771] (fs) DEBUG - fsmainloop receiving message..
  1097. [2017-08-16 11:48:12,515] (server) DEBUG - accepting new connection...
  1098. [2017-08-16 11:48:12,515] (request) DEBUG - handling connection from ('127.0.0.1', 46248)
  1099. [2017-08-16 11:48:12,516] (request) DEBUG - received request: ['PING']
  1100. [2017-08-16 11:48:12,516] (request) DEBUG - sending ping to cluster thread...
  1101. [2017-08-16 11:48:12,516] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1102. [2017-08-16 11:48:12,516] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d9a170>} to message Message(request=ping)
  1103. [2017-08-16 11:48:12,516] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2d9a170>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1104. [2017-08-16 11:48:12,517] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x2d9a170>, target=cluster)" to "cluster"...
  1105. [2017-08-16 11:48:13,772] (fs) DEBUG - timeout waiting for messages on queue
  1106. [2017-08-16 11:48:13,772] (fs) DEBUG - fsmainloop receiving message..
  1107. [2017-08-16 11:48:13,903] (db) DEBUG - creating new DB connection...
  1108. [2017-08-16 11:48:13,905] (db) DEBUG - users already verified..
  1109. [2017-08-16 11:48:13,905] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1110. [2017-08-16 11:48:13,906] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1111. [2017-08-16 11:48:13,907] (db) DEBUG - closing DB connection...
  1112. [2017-08-16 11:48:13,907] (db) DEBUG - mariadb status: running
  1113. [2017-08-16 11:48:15,772] (fs) DEBUG - timeout waiting for messages on queue
  1114. [2017-08-16 11:48:15,772] (fs) DEBUG - fsmainloop receiving message..
  1115. [2017-08-16 11:48:17,773] (fs) DEBUG - timeout waiting for messages on queue
  1116. [2017-08-16 11:48:17,773] (fs) DEBUG - fsmainloop receiving message..
  1117. [2017-08-16 11:48:17,907] (db) DEBUG - creating new DB connection...
  1118. [2017-08-16 11:48:17,909] (db) DEBUG - users already verified..
  1119. [2017-08-16 11:48:17,909] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1120. [2017-08-16 11:48:17,911] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1121. [2017-08-16 11:48:17,912] (db) DEBUG - closing DB connection...
  1122. [2017-08-16 11:48:17,912] (db) DEBUG - mariadb status: running
  1123. [2017-08-16 11:48:19,773] (fs) DEBUG - timeout waiting for messages on queue
  1124. [2017-08-16 11:48:19,773] (fs) DEBUG - fsmainloop - pinging...
  1125. [2017-08-16 11:48:19,773] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  1126. [2017-08-16 11:48:19,774] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  1127. [2017-08-16 11:48:19,775] (fs) DEBUG - Connection driver esl loaded
  1128. [2017-08-16 11:48:19,776] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  1129. [2017-08-16 11:48:19,776] (fs) DEBUG - Initialized base connection
  1130. [2017-08-16 11:48:19,776] (fs) DEBUG - Connection driver esl created
  1131. [2017-08-16 11:48:19,776] (fs) DEBUG - check_connection()
  1132. [2017-08-16 11:48:19,777] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  1133. [2017-08-16 11:48:19,779] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  1134. [2017-08-16 11:48:19,779] (fs) DEBUG - check_event(timeout=1)
  1135. [2017-08-16 11:48:19,781] (fs) DEBUG - sending status message to FS...
  1136. [2017-08-16 11:48:19,781] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  1137. [2017-08-16 11:48:19,781] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  1138. [2017-08-16 11:48:19,781] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3ae4a90>: ['BACKGROUND_JOB']
  1139. [2017-08-16 11:48:19,781] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  1140. [2017-08-16 11:48:19,783] (fs) DEBUG - waiting event on FS...
  1141. [2017-08-16 11:48:19,784] (fs) DEBUG - check_event(timeout=30000)
  1142. [2017-08-16 11:48:19,784] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  1143. [2017-08-16 11:48:19,784] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 45 minutes, 27 seconds, 809 milliseconds, 394 microseconds
  1144. [2017-08-16 11:48:19,784] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  1145. [2017-08-16 11:48:19,784] (fs) DEBUG - RESPONSE: 611389 session(s) since startup
  1146. [2017-08-16 11:48:19,784] (fs) DEBUG - RESPONSE: 899 session(s) - 0 out of max 150 per sec peak 9 (4 last 5min)
  1147. [2017-08-16 11:48:19,784] (fs) DEBUG - RESPONSE: 2000 session(s) max
  1148. [2017-08-16 11:48:19,784] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  1149. [2017-08-16 11:48:19,784] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  1150. [2017-08-16 11:48:19,792] (fs) DEBUG - fsmainloop receiving message..
  1151. [2017-08-16 11:48:21,792] (fs) DEBUG - timeout waiting for messages on queue
  1152. [2017-08-16 11:48:21,792] (fs) DEBUG - fsmainloop receiving message..
  1153. [2017-08-16 11:48:21,912] (db) DEBUG - creating new DB connection...
  1154. [2017-08-16 11:48:21,915] (db) DEBUG - users already verified..
  1155. [2017-08-16 11:48:21,915] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1156. [2017-08-16 11:48:21,916] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1157. [2017-08-16 11:48:21,917] (db) DEBUG - closing DB connection...
  1158. [2017-08-16 11:48:21,917] (db) DEBUG - mariadb status: running
  1159. [2017-08-16 11:48:23,793] (fs) DEBUG - timeout waiting for messages on queue
  1160. [2017-08-16 11:48:23,793] (fs) DEBUG - fsmainloop receiving message..
  1161. [2017-08-16 11:48:25,793] (fs) DEBUG - timeout waiting for messages on queue
  1162. [2017-08-16 11:48:25,793] (fs) DEBUG - fsmainloop receiving message..
  1163. [2017-08-16 11:48:25,918] (db) DEBUG - creating new DB connection...
  1164. [2017-08-16 11:48:25,919] (db) DEBUG - users already verified..
  1165. [2017-08-16 11:48:25,920] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1166. [2017-08-16 11:48:25,920] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1167. [2017-08-16 11:48:25,921] (db) DEBUG - closing DB connection...
  1168. [2017-08-16 11:48:25,921] (db) DEBUG - mariadb status: running
  1169. [2017-08-16 11:48:27,253] (server) DEBUG - accepting new connection...
  1170. [2017-08-16 11:48:27,253] (request) DEBUG - handling connection from ('127.0.0.1', 46264)
  1171. [2017-08-16 11:48:27,253] (request) DEBUG - received request: ['STATUS']
  1172. [2017-08-16 11:48:27,254] (request) DEBUG - querying status from led...
  1173. [2017-08-16 11:48:27,254] (request) DEBUG - querying status from fs...
  1174. [2017-08-16 11:48:27,254] (request) DEBUG - querying status from db...
  1175. [2017-08-16 11:48:27,254] (request) DEBUG - querying status from mon...
  1176. [2017-08-16 11:48:27,254] (request) DEBUG - querying status from cluster...
  1177. [2017-08-16 11:48:27,516] (server) DEBUG - accepting new connection...
  1178. [2017-08-16 11:48:27,516] (request) DEBUG - handling connection from ('127.0.0.1', 46266)
  1179. [2017-08-16 11:48:27,517] (request) DEBUG - received request: ['PING']
  1180. [2017-08-16 11:48:27,517] (request) DEBUG - sending ping to cluster thread...
  1181. [2017-08-16 11:48:27,517] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1182. [2017-08-16 11:48:27,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x27484d0>} to message Message(request=ping)
  1183. [2017-08-16 11:48:27,517] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x27484d0>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1184. [2017-08-16 11:48:27,517] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x27484d0>, target=cluster)" to "cluster"...
  1185. [2017-08-16 11:48:27,794] (fs) DEBUG - timeout waiting for messages on queue
  1186. [2017-08-16 11:48:27,794] (fs) DEBUG - fsmainloop receiving message..
  1187. [2017-08-16 11:48:29,794] (fs) DEBUG - timeout waiting for messages on queue
  1188. [2017-08-16 11:48:29,795] (fs) DEBUG - fsmainloop receiving message..
  1189. [2017-08-16 11:48:29,921] (db) DEBUG - creating new DB connection...
  1190. [2017-08-16 11:48:29,923] (db) DEBUG - users already verified..
  1191. [2017-08-16 11:48:29,923] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1192. [2017-08-16 11:48:29,924] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1193. [2017-08-16 11:48:29,925] (db) DEBUG - closing DB connection...
  1194. [2017-08-16 11:48:29,925] (db) DEBUG - mariadb status: running
  1195. [2017-08-16 11:48:31,795] (fs) DEBUG - timeout waiting for messages on queue
  1196. [2017-08-16 11:48:31,795] (fs) DEBUG - fsmainloop receiving message..
  1197. [2017-08-16 11:48:32,516] (request) DEBUG - got response from ping: False...
  1198. [2017-08-16 11:48:33,796] (fs) DEBUG - timeout waiting for messages on queue
  1199. [2017-08-16 11:48:33,796] (fs) DEBUG - fsmainloop receiving message..
  1200. [2017-08-16 11:48:33,925] (db) DEBUG - creating new DB connection...
  1201. [2017-08-16 11:48:33,927] (db) DEBUG - users already verified..
  1202. [2017-08-16 11:48:33,927] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1203. [2017-08-16 11:48:33,928] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1204. [2017-08-16 11:48:33,928] (db) DEBUG - closing DB connection...
  1205. [2017-08-16 11:48:33,928] (db) DEBUG - mariadb status: running
  1206. [2017-08-16 11:48:35,796] (fs) DEBUG - timeout waiting for messages on queue
  1207. [2017-08-16 11:48:35,797] (fs) DEBUG - fsmainloop - pinging...
  1208. [2017-08-16 11:48:35,797] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  1209. [2017-08-16 11:48:35,797] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  1210. [2017-08-16 11:48:35,797] (fs) DEBUG - Connection driver esl loaded
  1211. [2017-08-16 11:48:35,798] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  1212. [2017-08-16 11:48:35,798] (fs) DEBUG - Initialized base connection
  1213. [2017-08-16 11:48:35,798] (fs) DEBUG - Connection driver esl created
  1214. [2017-08-16 11:48:35,798] (fs) DEBUG - check_connection()
  1215. [2017-08-16 11:48:35,798] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  1216. [2017-08-16 11:48:35,802] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  1217. [2017-08-16 11:48:35,802] (fs) DEBUG - check_event(timeout=1)
  1218. [2017-08-16 11:48:35,803] (fs) DEBUG - sending status message to FS...
  1219. [2017-08-16 11:48:35,803] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  1220. [2017-08-16 11:48:35,803] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  1221. [2017-08-16 11:48:35,803] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x3a14cd0>: ['BACKGROUND_JOB']
  1222. [2017-08-16 11:48:35,804] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  1223. [2017-08-16 11:48:35,806] (fs) DEBUG - waiting event on FS...
  1224. [2017-08-16 11:48:35,806] (fs) DEBUG - check_event(timeout=30000)
  1225. [2017-08-16 11:48:35,806] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  1226. [2017-08-16 11:48:35,806] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 45 minutes, 43 seconds, 829 milliseconds, 388 microseconds
  1227. [2017-08-16 11:48:35,807] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  1228. [2017-08-16 11:48:35,807] (fs) DEBUG - RESPONSE: 611428 session(s) since startup
  1229. [2017-08-16 11:48:35,807] (fs) DEBUG - RESPONSE: 868 session(s) - 0 out of max 150 per sec peak 9 (2 last 5min)
  1230. [2017-08-16 11:48:35,807] (fs) DEBUG - RESPONSE: 2000 session(s) max
  1231. [2017-08-16 11:48:35,807] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  1232. [2017-08-16 11:48:35,807] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  1233. [2017-08-16 11:48:35,814] (fs) DEBUG - fsmainloop receiving message..
  1234. [2017-08-16 11:48:37,814] (fs) DEBUG - timeout waiting for messages on queue
  1235. [2017-08-16 11:48:37,814] (fs) DEBUG - fsmainloop receiving message..
  1236. [2017-08-16 11:48:37,929] (db) DEBUG - creating new DB connection...
  1237. [2017-08-16 11:48:37,930] (db) DEBUG - users already verified..
  1238. [2017-08-16 11:48:37,930] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1239. [2017-08-16 11:48:37,931] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1240. [2017-08-16 11:48:37,932] (db) DEBUG - closing DB connection...
  1241. [2017-08-16 11:48:37,932] (db) DEBUG - mariadb status: running
  1242. [2017-08-16 11:48:39,815] (fs) DEBUG - timeout waiting for messages on queue
  1243. [2017-08-16 11:48:39,815] (fs) DEBUG - fsmainloop receiving message..
  1244. [2017-08-16 11:48:41,815] (fs) DEBUG - timeout waiting for messages on queue
  1245. [2017-08-16 11:48:41,816] (fs) DEBUG - fsmainloop receiving message..
  1246. [2017-08-16 11:48:41,932] (db) DEBUG - creating new DB connection...
  1247. [2017-08-16 11:48:41,934] (db) DEBUG - users already verified..
  1248. [2017-08-16 11:48:41,935] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1249. [2017-08-16 11:48:41,936] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1250. [2017-08-16 11:48:41,937] (db) DEBUG - closing DB connection...
  1251. [2017-08-16 11:48:41,937] (db) DEBUG - mariadb status: running
  1252. [2017-08-16 11:48:43,816] (fs) DEBUG - timeout waiting for messages on queue
  1253. [2017-08-16 11:48:43,816] (fs) DEBUG - fsmainloop receiving message..
  1254. [2017-08-16 11:48:45,817] (fs) DEBUG - timeout waiting for messages on queue
  1255. [2017-08-16 11:48:45,817] (fs) DEBUG - fsmainloop receiving message..
  1256. [2017-08-16 11:48:45,938] (db) DEBUG - creating new DB connection...
  1257. [2017-08-16 11:48:45,939] (db) DEBUG - users already verified..
  1258. [2017-08-16 11:48:45,939] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1259. [2017-08-16 11:48:45,940] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1260. [2017-08-16 11:48:45,941] (db) DEBUG - closing DB connection...
  1261. [2017-08-16 11:48:45,941] (db) DEBUG - mariadb status: running
  1262. [2017-08-16 11:48:47,291] (server) DEBUG - accepting new connection...
  1263. [2017-08-16 11:48:47,292] (request) DEBUG - handling connection from ('127.0.0.1', 46274)
  1264. [2017-08-16 11:48:47,292] (request) DEBUG - received request: ['STATUS']
  1265. [2017-08-16 11:48:47,292] (request) DEBUG - querying status from led...
  1266. [2017-08-16 11:48:47,292] (request) DEBUG - querying status from fs...
  1267. [2017-08-16 11:48:47,292] (request) DEBUG - querying status from db...
  1268. [2017-08-16 11:48:47,293] (request) DEBUG - querying status from mon...
  1269. [2017-08-16 11:48:47,293] (request) DEBUG - querying status from cluster...
  1270. [2017-08-16 11:48:47,517] (request) DEBUG - got response from ping: False...
  1271. [2017-08-16 11:48:47,817] (fs) DEBUG - timeout waiting for messages on queue
  1272. [2017-08-16 11:48:47,817] (fs) DEBUG - fsmainloop receiving message..
  1273. [2017-08-16 11:48:49,818] (fs) DEBUG - timeout waiting for messages on queue
  1274. [2017-08-16 11:48:49,818] (fs) DEBUG - fsmainloop receiving message..
  1275. [2017-08-16 11:48:49,941] (db) DEBUG - creating new DB connection...
  1276. [2017-08-16 11:48:49,942] (db) DEBUG - users already verified..
  1277. [2017-08-16 11:48:49,943] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1278. [2017-08-16 11:48:49,943] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1279. [2017-08-16 11:48:49,944] (db) DEBUG - closing DB connection...
  1280. [2017-08-16 11:48:49,944] (db) DEBUG - mariadb status: running
  1281. [2017-08-16 11:48:51,818] (fs) DEBUG - timeout waiting for messages on queue
  1282. [2017-08-16 11:48:51,818] (fs) DEBUG - fsmainloop - pinging...
  1283. [2017-08-16 11:48:51,818] (fs) DEBUG - Creating connection to esl://ClueCon@localhost:8021
  1284. [2017-08-16 11:48:51,819] (fs) DEBUG - Loading oswc.esl_connection_driver from /opt/rh/python27/root/usr/lib/python2.7/site-packages/oswc/esl_connection_driver.py
  1285. [2017-08-16 11:48:51,819] (fs) DEBUG - Connection driver esl loaded
  1286. [2017-08-16 11:48:51,819] (fs) DEBUG - Starting ESL connection to esl://ClueCon@localhost:8021
  1287. [2017-08-16 11:48:51,819] (fs) DEBUG - Initialized base connection
  1288. [2017-08-16 11:48:51,819] (fs) DEBUG - Connection driver esl created
  1289. [2017-08-16 11:48:51,820] (fs) DEBUG - check_connection()
  1290. [2017-08-16 11:48:51,820] (fs) DEBUG - ESL connecting to esl://ClueCon@localhost:8021 (host=localhost, port=8021, user=ClueCon)
  1291. [2017-08-16 11:48:51,824] (fs) DEBUG - ESL connection to esl://ClueCon@localhost:8021 succeeded!
  1292. [2017-08-16 11:48:51,824] (fs) DEBUG - check_event(timeout=1)
  1293. [2017-08-16 11:48:51,825] (fs) DEBUG - sending status message to FS...
  1294. [2017-08-16 11:48:51,825] (fs) DEBUG - Executing ESL CMD 'status' ARGS 'None'
  1295. [2017-08-16 11:48:51,825] (fs) DEBUG - Setting event listener filter: ['BACKGROUND_JOB']
  1296. [2017-08-16 11:48:51,825] (fs) DEBUG - Adding listener <oswc.esl_connection_driver.BackgroundJobListener object at 0x39f2810>: ['BACKGROUND_JOB']
  1297. [2017-08-16 11:48:51,826] (fs) DEBUG - Now listening for ESL event BACKGROUND_JOB
  1298. [2017-08-16 11:48:51,828] (fs) DEBUG - waiting event on FS...
  1299. [2017-08-16 11:48:51,828] (fs) DEBUG - check_event(timeout=30000)
  1300. [2017-08-16 11:48:51,828] (fs) DEBUG - Received event of type: BACKGROUND_JOB/None
  1301. [2017-08-16 11:48:51,828] (fs) DEBUG - RESPONSE: UP 0 years, 5 days, 9 hours, 45 minutes, 59 seconds, 849 milliseconds, 388 microseconds
  1302. [2017-08-16 11:48:51,828] (fs) DEBUG - RESPONSE: FreeSWITCH is ready
  1303. [2017-08-16 11:48:51,828] (fs) DEBUG - RESPONSE: 611480 session(s) since startup
  1304. [2017-08-16 11:48:51,828] (fs) DEBUG - RESPONSE: 852 session(s) - 0 out of max 150 per sec peak 9 (3 last 5min)
  1305. [2017-08-16 11:48:51,828] (fs) DEBUG - RESPONSE: 2000 session(s) max
  1306. [2017-08-16 11:48:51,828] (fs) DEBUG - RESPONSE: min idle cpu 0.00/94.00
  1307. [2017-08-16 11:48:51,829] (fs) DEBUG - got event BACKGROUND_JOB on FS...
  1308. [2017-08-16 11:48:51,835] (fs) DEBUG - fsmainloop receiving message..
  1309. [2017-08-16 11:48:53,836] (fs) DEBUG - timeout waiting for messages on queue
  1310. [2017-08-16 11:48:53,836] (fs) DEBUG - fsmainloop receiving message..
  1311. [2017-08-16 11:48:53,945] (db) DEBUG - creating new DB connection...
  1312. [2017-08-16 11:48:53,946] (db) DEBUG - users already verified..
  1313. [2017-08-16 11:48:53,946] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1314. [2017-08-16 11:48:53,947] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1315. [2017-08-16 11:48:53,948] (db) DEBUG - closing DB connection...
  1316. [2017-08-16 11:48:53,948] (db) DEBUG - mariadb status: running
  1317. [2017-08-16 11:48:55,836] (fs) DEBUG - timeout waiting for messages on queue
  1318. [2017-08-16 11:48:55,836] (fs) DEBUG - fsmainloop receiving message..
  1319. [2017-08-16 11:48:57,513] (server) DEBUG - accepting new connection...
  1320. [2017-08-16 11:48:57,514] (request) DEBUG - handling connection from ('127.0.0.1', 46306)
  1321. [2017-08-16 11:48:57,515] (request) DEBUG - received request: ['PING']
  1322. [2017-08-16 11:48:57,515] (request) DEBUG - sending ping to cluster thread...
  1323. [2017-08-16 11:48:57,515] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1324. [2017-08-16 11:48:57,515] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x26bae60>} to message Message(request=ping)
  1325. [2017-08-16 11:48:57,515] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x26bae60>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1326. [2017-08-16 11:48:57,516] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x26bae60>, target=cluster)" to "cluster"...
  1327. [2017-08-16 11:48:57,578] (server) DEBUG - accepting new connection...
  1328. [2017-08-16 11:48:57,578] (request) DEBUG - handling connection from ('127.0.0.1', 46308)
  1329. [2017-08-16 11:48:57,579] (request) DEBUG - received request: ['STATUS']
  1330. [2017-08-16 11:48:57,579] (request) DEBUG - querying status from led...
  1331. [2017-08-16 11:48:57,579] (request) DEBUG - querying status from fs...
  1332. [2017-08-16 11:48:57,579] (request) DEBUG - querying status from db...
  1333. [2017-08-16 11:48:57,579] (request) DEBUG - querying status from mon...
  1334. [2017-08-16 11:48:57,579] (request) DEBUG - querying status from cluster...
  1335. [2017-08-16 11:48:57,712] (root) INFO - enabling debug logging...
  1336. [2017-08-16 11:48:57,713] (cluster) INFO - received termination request, exiting...
  1337. [2017-08-16 11:48:57,713] (inotify.adapters) DEBUG - Removing watch for watch-handle (1): [/var/lib/pacemaker/cib/]
  1338. [2017-08-16 11:48:57,713] (inotify.adapters) DEBUG - Removing watch for watch-handle (2): [/var/sngmonit/state]
  1339. [2017-08-16 11:48:57,713] (root) DEBUG - broadcasting stop request for threads...
  1340. [2017-08-16 11:48:57,713] (root) DEBUG - sending message "None" to "led"...
  1341. [2017-08-16 11:48:57,714] (root) DEBUG - sending message "None" to "fs"...
  1342. [2017-08-16 11:48:57,714] (root) DEBUG - sending message "None" to "mon"...
  1343. [2017-08-16 11:48:57,714] (root) DEBUG - popener(['service', 'pacemaker', 'stop'], {} - {'stdout': 9, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 31})
  1344. [2017-08-16 11:48:57,729] (monit) DEBUG - exit request, bailing out
  1345. [2017-08-16 11:48:57,754] (fs) DEBUG - exit request, bailing out
  1346. [2017-08-16 11:48:57,948] (db) DEBUG - creating new DB connection...
  1347. [2017-08-16 11:48:57,950] (db) DEBUG - users already verified..
  1348. [2017-08-16 11:48:57,950] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1349. [2017-08-16 11:48:57,951] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1350. [2017-08-16 11:48:57,952] (db) DEBUG - closing DB connection...
  1351. [2017-08-16 11:48:57,953] (db) DEBUG - mariadb status: running
  1352. [2017-08-16 11:49:01,953] (db) DEBUG - creating new DB connection...
  1353. [2017-08-16 11:49:01,955] (db) DEBUG - users already verified..
  1354. [2017-08-16 11:49:01,955] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1355. [2017-08-16 11:49:01,956] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1356. [2017-08-16 11:49:01,956] (db) DEBUG - closing DB connection...
  1357. [2017-08-16 11:49:01,956] (db) DEBUG - mariadb status: running
  1358. [2017-08-16 11:49:02,518] (request) DEBUG - got response from ping: False...
  1359. [2017-08-16 11:49:05,957] (db) DEBUG - creating new DB connection...
  1360. [2017-08-16 11:49:05,958] (db) DEBUG - users already verified..
  1361. [2017-08-16 11:49:05,958] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1362. [2017-08-16 11:49:05,959] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1363. [2017-08-16 11:49:05,960] (db) DEBUG - closing DB connection...
  1364. [2017-08-16 11:49:05,960] (db) DEBUG - mariadb status: running
  1365. [2017-08-16 11:49:07,310] (server) DEBUG - accepting new connection...
  1366. [2017-08-16 11:49:07,311] (request) DEBUG - handling connection from ('127.0.0.1', 46318)
  1367. [2017-08-16 11:49:07,311] (request) DEBUG - received request: ['STATUS']
  1368. [2017-08-16 11:49:07,311] (request) DEBUG - querying status from led...
  1369. [2017-08-16 11:49:07,311] (request) DEBUG - querying status from fs...
  1370. [2017-08-16 11:49:07,311] (request) DEBUG - querying status from db...
  1371. [2017-08-16 11:49:07,311] (request) DEBUG - querying status from mon...
  1372. [2017-08-16 11:49:07,311] (request) DEBUG - querying status from cluster...
  1373. [2017-08-16 11:49:09,961] (db) DEBUG - creating new DB connection...
  1374. [2017-08-16 11:49:09,962] (db) DEBUG - users already verified..
  1375. [2017-08-16 11:49:09,962] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1376. [2017-08-16 11:49:09,963] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1377. [2017-08-16 11:49:09,964] (db) DEBUG - closing DB connection...
  1378. [2017-08-16 11:49:09,964] (db) DEBUG - mariadb status: running
  1379. [2017-08-16 11:49:12,514] (server) DEBUG - accepting new connection...
  1380. [2017-08-16 11:49:12,515] (request) DEBUG - handling connection from ('127.0.0.1', 46338)
  1381. [2017-08-16 11:49:12,515] (request) DEBUG - received request: ['PING']
  1382. [2017-08-16 11:49:12,515] (request) DEBUG - sending ping to cluster thread...
  1383. [2017-08-16 11:49:12,515] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1384. [2017-08-16 11:49:12,515] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2748c68>} to message Message(request=ping)
  1385. [2017-08-16 11:49:12,515] (root) DEBUG - skipping thread "cluster", not running...
  1386. [2017-08-16 11:49:12,515] (request) DEBUG - got response from ping: None...
  1387. [2017-08-16 11:49:13,964] (db) DEBUG - creating new DB connection...
  1388. [2017-08-16 11:49:13,966] (db) DEBUG - users already verified..
  1389. [2017-08-16 11:49:13,966] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1390. [2017-08-16 11:49:13,967] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1391. [2017-08-16 11:49:13,968] (db) DEBUG - closing DB connection...
  1392. [2017-08-16 11:49:13,968] (db) DEBUG - mariadb status: running
  1393. [2017-08-16 11:49:15,956] (sngpyutils.io.popener) INFO - pacemaker[29282] Waiting for shutdown of managed resources.........[  OK  ]
  1394. [2017-08-16 11:49:16,996] (sngpyutils.io.popener) INFO - pacemaker[29282] Leaving fence domain[  OK  ]
  1395. Stopping fenced 17389[  OK  ]
  1396. Signaling Pacemaker Cluster Manager to terminate[  OK  ]
  1397. [2017-08-16 11:49:17,968] (db) DEBUG - creating new DB connection...
  1398. [2017-08-16 11:49:17,969] (db) DEBUG - users already verified..
  1399. [2017-08-16 11:49:17,970] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1400. [2017-08-16 11:49:17,970] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1401. [2017-08-16 11:49:17,971] (db) INFO - cluster size changed from "2" to "1"
  1402. [2017-08-16 11:49:17,971] (db) DEBUG - wsrep_incoming_addresses: changed from "10.10.150.2:3307,10.10.150.3:3307" to "10.10.150.3:3307"
  1403. [2017-08-16 11:49:17,971] (db) DEBUG - closing DB connection...
  1404. [2017-08-16 11:49:17,971] (db) DEBUG - mariadb status: running
  1405. [2017-08-16 11:49:21,972] (db) DEBUG - creating new DB connection...
  1406. [2017-08-16 11:49:21,973] (db) DEBUG - users already verified..
  1407. [2017-08-16 11:49:21,973] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1408. [2017-08-16 11:49:21,974] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1409. [2017-08-16 11:49:21,974] (db) DEBUG - closing DB connection...
  1410. [2017-08-16 11:49:21,974] (db) DEBUG - mariadb status: running
  1411. [2017-08-16 11:49:25,975] (db) DEBUG - creating new DB connection...
  1412. [2017-08-16 11:49:25,976] (db) DEBUG - users already verified..
  1413. [2017-08-16 11:49:25,977] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1414. [2017-08-16 11:49:25,977] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1415. [2017-08-16 11:49:25,978] (db) DEBUG - closing DB connection...
  1416. [2017-08-16 11:49:25,978] (db) DEBUG - mariadb status: running
  1417. [2017-08-16 11:49:27,515] (server) DEBUG - accepting new connection...
  1418. [2017-08-16 11:49:27,515] (request) DEBUG - handling connection from ('127.0.0.1', 46360)
  1419. [2017-08-16 11:49:27,516] (request) DEBUG - received request: ['PING']
  1420. [2017-08-16 11:49:27,516] (request) DEBUG - sending ping to cluster thread...
  1421. [2017-08-16 11:49:27,516] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1422. [2017-08-16 11:49:27,516] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x2748998>} to message Message(request=ping)
  1423. [2017-08-16 11:49:27,516] (root) DEBUG - skipping thread "cluster", not running...
  1424. [2017-08-16 11:49:27,516] (request) DEBUG - got response from ping: None...
  1425. [2017-08-16 11:49:27,569] (server) DEBUG - accepting new connection...
  1426. [2017-08-16 11:49:27,569] (request) DEBUG - handling connection from ('127.0.0.1', 46364)
  1427. [2017-08-16 11:49:27,570] (request) DEBUG - received request: ['STATUS']
  1428. [2017-08-16 11:49:27,570] (request) DEBUG - querying status from led...
  1429. [2017-08-16 11:49:27,570] (request) DEBUG - querying status from fs...
  1430. [2017-08-16 11:49:27,570] (request) DEBUG - querying status from db...
  1431. [2017-08-16 11:49:27,570] (request) DEBUG - querying status from mon...
  1432. [2017-08-16 11:49:27,570] (request) DEBUG - querying status from cluster...
  1433. [2017-08-16 11:49:29,978] (db) DEBUG - creating new DB connection...
  1434. [2017-08-16 11:49:29,980] (db) DEBUG - users already verified..
  1435. [2017-08-16 11:49:29,980] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1436. [2017-08-16 11:49:29,981] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1437. [2017-08-16 11:49:29,982] (db) DEBUG - closing DB connection...
  1438. [2017-08-16 11:49:29,982] (db) DEBUG - mariadb status: running
  1439. [2017-08-16 11:49:32,516] (request) DEBUG - got response from ping: False...
  1440. [2017-08-16 11:49:33,982] (db) DEBUG - creating new DB connection...
  1441. [2017-08-16 11:49:33,983] (db) DEBUG - users already verified..
  1442. [2017-08-16 11:49:33,984] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1443. [2017-08-16 11:49:33,984] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1444. [2017-08-16 11:49:33,985] (db) DEBUG - closing DB connection...
  1445. [2017-08-16 11:49:33,985] (db) DEBUG - mariadb status: running
  1446. [2017-08-16 11:49:37,986] (db) DEBUG - creating new DB connection...
  1447. [2017-08-16 11:49:37,987] (db) DEBUG - users already verified..
  1448. [2017-08-16 11:49:37,987] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1449. [2017-08-16 11:49:37,988] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1450. [2017-08-16 11:49:37,989] (db) DEBUG - closing DB connection...
  1451. [2017-08-16 11:49:37,989] (db) DEBUG - mariadb status: running
  1452. [2017-08-16 11:49:41,064] (sngpyutils.io.popener) INFO - pacemaker[29282] Waiting for cluster services to unload........................[  OK  ]
  1453. [2017-08-16 11:49:41,088] (sngpyutils.io.popener) INFO - pacemaker[29282] Stopping cluster:
  1454. [2017-08-16 11:49:41,107] (sngpyutils.io.popener) INFO - pacemaker[29282]    Leaving fence domain... [  OK  ]
  1455. [2017-08-16 11:49:41,415] (sngpyutils.io.popener) INFO - pacemaker[29282]    Stopping gfs_controld... [  OK  ]
  1456. [2017-08-16 11:49:41,730] (sngpyutils.io.popener) INFO - pacemaker[29282]    Stopping dlm_controld... [  OK  ]
  1457. [2017-08-16 11:49:41,777] (sngpyutils.io.popener) INFO - pacemaker[29282]    Stopping fenced... [  OK  ]
  1458. [2017-08-16 11:49:41,989] (db) DEBUG - creating new DB connection...
  1459. [2017-08-16 11:49:41,991] (db) DEBUG - users already verified..
  1460. [2017-08-16 11:49:41,991] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1461. [2017-08-16 11:49:41,992] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1462. [2017-08-16 11:49:41,992] (db) DEBUG - closing DB connection...
  1463. [2017-08-16 11:49:41,993] (db) DEBUG - mariadb status: running
  1464. [2017-08-16 11:49:42,797] (sngpyutils.io.popener) INFO - pacemaker[29282]    Stopping cman... [  OK  ]
  1465. [2017-08-16 11:49:42,816] (sngpyutils.io.popener) INFO - pacemaker[29282]    Waiting for corosync to shutdown:[  OK  ]
  1466. [2017-08-16 11:49:42,828] (sngpyutils.io.popener) INFO - pacemaker[29282]    Unloading kernel modules... [  OK  ]
  1467. [2017-08-16 11:49:42,863] (sngpyutils.io.popener) INFO - pacemaker[29282]    Unmounting configfs... [  OK  ]
  1468. [2017-08-16 11:49:43,285] (root) DEBUG - popener(['service', 'cman', 'stop'], {} - {'stdout': 9, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x22fd270>, 'stderr': 25})
  1469. [2017-08-16 11:49:43,324] (sngpyutils.io.popener) INFO - cman[30773] Stopping cluster:
  1470. [2017-08-16 11:49:43,342] (sngpyutils.io.popener) INFO - cman[30773]    Leaving fence domain... [  OK  ]
  1471. [2017-08-16 11:49:43,388] (sngpyutils.io.popener) INFO - cman[30773]    Stopping gfs_controld... [  OK  ]
  1472. [2017-08-16 11:49:43,430] (sngpyutils.io.popener) INFO - cman[30773]    Stopping dlm_controld... [  OK  ]
  1473. [2017-08-16 11:49:43,474] (sngpyutils.io.popener) INFO - cman[30773]    Stopping fenced... [  OK  ]
  1474. [2017-08-16 11:49:43,478] (sngpyutils.io.popener) INFO - cman[30773]    Stopping cman... [  OK  ]
  1475. [2017-08-16 11:49:43,483] (sngpyutils.io.popener) INFO - cman[30773]    Unloading kernel modules... [  OK  ]
  1476. [2017-08-16 11:49:43,485] (sngpyutils.io.popener) INFO - cman[30773]    Unmounting configfs... [  OK  ]
  1477. [2017-08-16 11:49:43,803] (root) DEBUG - broadcasting stop request for threads...
  1478. [2017-08-16 11:49:43,803] (root) DEBUG - sending message "None" to "db"...
  1479. [2017-08-16 11:49:43,803] (root) DEBUG - stopping requests thread..
  1480. [2017-08-16 11:49:44,139] (root) INFO - enabling debug logging...
  1481. [2017-08-16 11:49:44,141] (root) DEBUG - starting requests thread..
  1482. [2017-08-16 11:49:44,142] (root) DEBUG - starting thread "db"...
  1483. [2017-08-16 11:49:44,142] (server) DEBUG - starting status server..
  1484. [2017-08-16 11:49:44,142] (server) DEBUG - waiting for clients...
  1485. [2017-08-16 11:49:44,142] (mariadb) DEBUG - popener(['/opt/mariadb-galera/bin/my_print_defaults', '-c', '/etc/mariadb.cnf', 'mysqld_safe'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 11, 'stdout': 9})
  1486. [2017-08-16 11:49:44,145] (root) DEBUG - monitor config MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical])
  1487. [2017-08-16 11:49:44,147] (cluster) DEBUG - starting cluster services...
  1488. [2017-08-16 11:49:44,148] (root) INFO - binding locally on mcast ports (primary = 5405, backup = 5405)
  1489. [2017-08-16 11:49:44,149] (root) DEBUG - popener(['service', 'cman', 'start'], {} - {'stdout': 15, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 17})
  1490. [2017-08-16 11:49:44,150] (mariadb) INFO - DB running with pid 2254...
  1491. [2017-08-16 11:49:44,150] (mariadb) INFO - DB running with pid 2254...
  1492. [2017-08-16 11:49:44,154] (server) DEBUG - accepting new connection...
  1493. [2017-08-16 11:49:44,154] (request) DEBUG - handling connection from ('127.0.0.1', 46374)
  1494. [2017-08-16 11:49:44,155] (request) DEBUG - received request: ['PING']
  1495. [2017-08-16 11:49:44,155] (request) DEBUG - sending ping to cluster thread...
  1496. [2017-08-16 11:49:44,155] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1497. [2017-08-16 11:49:44,155] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x1e22878>} to message Message(request=ping)
  1498. [2017-08-16 11:49:44,155] (root) DEBUG - skipping thread "cluster", not running...
  1499. [2017-08-16 11:49:44,155] (request) DEBUG - got response from ping: None...
  1500. [2017-08-16 11:49:44,168] (sngpyutils.io.popener) INFO - cman[30855] Starting cluster:
  1501. [2017-08-16 11:49:44,169] (sngpyutils.io.popener) INFO - cman[30855]    Checking if cluster has been disabled at boot... [  OK  ]
  1502. [2017-08-16 11:49:44,186] (sngpyutils.io.popener) INFO - cman[30855]    Checking Network Manager... [  OK  ]
  1503. [2017-08-16 11:49:44,187] (sngpyutils.io.popener) INFO - cman[30855]    Global setup... [  OK  ]
  1504. [2017-08-16 11:49:44,191] (sngpyutils.io.popener) INFO - cman[30855]    Loading kernel modules... [  OK  ]
  1505. [2017-08-16 11:49:44,194] (sngpyutils.io.popener) INFO - cman[30855]    Mounting configfs... [  OK  ]
  1506. [2017-08-16 11:49:45,151] (mariadb) INFO - DB running with pid 2254...
  1507. [2017-08-16 11:49:46,151] (mariadb) INFO - DB running with pid 2254...
  1508. [2017-08-16 11:49:47,152] (mariadb) INFO - DB running with pid 2254...
  1509. [2017-08-16 11:49:48,152] (mariadb) DEBUG - unable to read pidfile: [Errno 2] No such file or directory: '/var/run/mariadb/mariadb.pid'
  1510. [2017-08-16 11:49:48,152] (mariadb) INFO - process terminated with TERM signal
  1511. [2017-08-16 11:49:48,153] (db) DEBUG - wrote address as "gcomm://", slave mode False, slave cleaning False
  1512. [2017-08-16 11:49:48,153] (db) DEBUG - mariadb status: NOT running
  1513. [2017-08-16 11:49:48,153] (mariadb) DEBUG - unable to read pidfile: [Errno 2] No such file or directory: '/var/run/mariadb/mariadb.pid'
  1514. [2017-08-16 11:49:48,153] (db) INFO - starting mariadbgalera...
  1515. [2017-08-16 11:49:48,153] (mariadb) DEBUG - asserting path /var/log/mariadb.log (mode = 640, is_dir = False)
  1516. [2017-08-16 11:49:48,154] (mariadb) DEBUG - changing ownership of /var/log/mariadb.log to (27, 27)
  1517. [2017-08-16 11:49:48,154] (mariadb) DEBUG - popener(['/sbin/restorecon', '/var/log/mariadb.log'], {} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 18, 'stdout': 15})
  1518. [2017-08-16 11:49:48,157] (mariadb) DEBUG - popener(['/opt/mariadb-galera/bin/my_print_defaults', '-c', '/etc/mariadb.cnf', 'mysqld'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 18, 'stdout': 17})
  1519. [2017-08-16 11:49:48,160] (mariadb) DEBUG - asserting path /var/lib/mariadb (mode = 755, is_dir = True)
  1520. [2017-08-16 11:49:48,160] (mariadb) DEBUG - changing ownership of /var/lib/mariadb to (27, 27)
  1521. [2017-08-16 11:49:48,160] (mariadb) DEBUG - popener(['/sbin/restorecon', '/var/lib/mariadb'], {} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 18, 'stdout': 15})
  1522. [2017-08-16 11:49:48,162] (mariadb) DEBUG - popener(['/usr/local/sng/bin/sng-spawn-subprocess', '/opt/mariadb-galera/bin/mysqld', '--defaults-file=/etc/mariadb.cnf', '--datadir=/var/lib/mariadb', '--socket=/var/lib/mariadb/mariadb.sock', '--pid-file=/var/run/mariadb/mariadb.pid', '--basedir=/opt/mariadb-galera', '--user=mysql', '--wsrep_recover', '--log_error=/var/lib/mariadb/wsrep_recovery.8mtFyn.log', '--pid-file=/var/lib/mariadb/S1-SBC01.e-contact.cl-recover.pid'], {'cwd': '/opt/mariadb-galera'} - {'stdout': 17, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'cwd': '/opt/mariadb-galera'})
  1523. [2017-08-16 11:49:48,177] (sngpyutils.io.popener) INFO - mysqld[31007] 170816 11:49:48 [Note] /opt/mariadb-galera/bin/mysqld (mysqld 10.0.23-MariaDB-wsrep-log) starting as process 31008 ...
  1524. [2017-08-16 11:49:48,309] (server) DEBUG - accepting new connection...
  1525. [2017-08-16 11:49:48,310] (request) DEBUG - handling connection from ('127.0.0.1', 46382)
  1526. [2017-08-16 11:49:48,310] (request) DEBUG - received request: ['STATUS']
  1527. [2017-08-16 11:49:48,310] (request) DEBUG - querying status from led...
  1528. [2017-08-16 11:49:48,310] (request) DEBUG - querying status from fs...
  1529. [2017-08-16 11:49:48,310] (request) DEBUG - querying status from db...
  1530. [2017-08-16 11:49:48,310] (request) DEBUG - querying status from mon...
  1531. [2017-08-16 11:49:48,310] (request) DEBUG - querying status from cluster...
  1532. [2017-08-16 11:49:48,320] (sngpyutils.io.popener) INFO - cman[30855]    Starting cman... [  OK  ]
  1533. [2017-08-16 11:49:48,328] (sngpyutils.io.popener) INFO - cman[30855]    Waiting for quorum... [  OK  ]
  1534. [2017-08-16 11:49:48,354] (sngpyutils.io.popener) INFO - cman[30855]    Starting fenced... [  OK  ]
  1535. [2017-08-16 11:49:49,375] (sngpyutils.io.popener) INFO - cman[30855]    Starting dlm_controld... [  OK  ]
  1536. [2017-08-16 11:49:49,376] (sngpyutils.io.popener) INFO - cman[30855]    Tuning DLM kernel config... [  OK  ]
  1537. [2017-08-16 11:49:49,394] (sngpyutils.io.popener) INFO - cman[30855]    Starting gfs_controld... [  OK  ]
  1538. [2017-08-16 11:49:49,420] (sngpyutils.io.popener) INFO - cman[30855]    Unfencing self... [  OK  ]
  1539. [2017-08-16 11:49:50,468] (sngpyutils.io.popener) INFO - cman[30855]    Joining fence domain... [  OK  ]
  1540. [2017-08-16 11:49:50,494] (mariadb) INFO - WSREP: recovered position 75035b86-4b44-11e7-b697-1617bbabffa1:11841
  1541. [2017-08-16 11:49:50,494] (mariadb) DEBUG - popener(['/usr/local/sng/bin/sng-spawn-subprocess', '/opt/mariadb-galera/bin/mysqld', '--defaults-file=/etc/mariadb.cnf', '--datadir=/var/lib/mariadb', '--socket=/var/lib/mariadb/mariadb.sock', '--pid-file=/var/run/mariadb/mariadb.pid', '--basedir=/opt/mariadb-galera', '--user=mysql', '--wsrep_start_position=75035b86-4b44-11e7-b697-1617bbabffa1:11841'], {'cwd': '/opt/mariadb-galera'} - {'stdout': 11, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 16, 'cwd': '/opt/mariadb-galera'})
  1542. [2017-08-16 11:49:50,511] (sngpyutils.io.popener) INFO - mysqld[31237] 170816 11:49:50 [Note] /opt/mariadb-galera/bin/mysqld (mysqld 10.0.23-MariaDB-wsrep-log) starting as process 31238 ...
  1543. [2017-08-16 11:49:50,653] (root) DEBUG - popener(['service', 'pacemaker', 'start'], {} - {'stdout': 16, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 18})
  1544. [2017-08-16 11:49:54,497] (db) DEBUG - creating new DB connection...
  1545. [2017-08-16 11:49:54,502] (db) DEBUG - monitor config not received, cannot verify users yet
  1546. [2017-08-16 11:49:54,502] (db) DEBUG - closing DB connection...
  1547. [2017-08-16 11:49:54,502] (db) DEBUG - mariadb status: running
  1548. [2017-08-16 11:49:54,503] (db) INFO - reload pending, restarting service...
  1549. [2017-08-16 11:49:54,503] (db) INFO - stopping mariadbgalera...
  1550. [2017-08-16 11:49:55,748] (sngpyutils.io.popener) INFO - pacemaker[31267] Starting Pacemaker Cluster Manager[  OK  ]
  1551. [2017-08-16 11:49:56,157] (root) DEBUG - starting thread "led"...
  1552. [2017-08-16 11:49:56,158] (root) DEBUG - starting thread "fs"...
  1553. [2017-08-16 11:49:56,158] (fs) DEBUG - fsmainloop receiving message..
  1554. [2017-08-16 11:49:56,158] (root) DEBUG - starting thread "mon"...
  1555. [2017-08-16 11:49:56,158] (inotify.adapters) DEBUG - Inotify handle is (16).
  1556. [2017-08-16 11:49:56,158] (inotify.adapters) DEBUG - Adding watch: [/var/lib/pacemaker/cib/]
  1557. [2017-08-16 11:49:56,158] (inotify.adapters) DEBUG - Added watch (1): [/var/lib/pacemaker/cib/]
  1558. [2017-08-16 11:49:56,158] (inotify.adapters) DEBUG - Adding watch: [/var/sngmonit/state]
  1559. [2017-08-16 11:49:56,158] (inotify.adapters) DEBUG - Added watch (2): [/var/sngmonit/state]
  1560. [2017-08-16 11:49:56,159] (root) DEBUG - adding {'config': <__main__.MonitorConfig object at 0x1e24210>} to message Message()
  1561. [2017-08-16 11:49:56,159] (root) DEBUG - adding {'config': <__main__.MonitorConfig object at 0x1e24210>, 'target': 'led'} to message Message()
  1562. [2017-08-16 11:49:56,159] (root) DEBUG - sending message "Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=led)" to "led"...
  1563. [2017-08-16 11:49:56,159] (root) DEBUG - adding {'config': <__main__.MonitorConfig object at 0x1e24210>, 'target': 'fs'} to message Message()
  1564. [2017-08-16 11:49:56,159] (root) DEBUG - sending message "Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=fs)" to "fs"...
  1565. [2017-08-16 11:49:56,159] (root) DEBUG - adding {'config': <__main__.MonitorConfig object at 0x1e24210>, 'target': 'db'} to message Message()
  1566. [2017-08-16 11:49:56,159] (root) DEBUG - sending message "Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=db)" to "db"...
  1567. [2017-08-16 11:49:56,159] (fs) DEBUG - received message Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=fs)
  1568. [2017-08-16 11:49:56,159] (root) DEBUG - adding {'config': <__main__.MonitorConfig object at 0x1e24210>, 'target': 'mon'} to message Message()
  1569. [2017-08-16 11:49:56,159] (fs) DEBUG - fsmainloop receiving message..
  1570. [2017-08-16 11:49:56,160] (root) DEBUG - sending message "Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=mon)" to "mon"...
  1571. [2017-08-16 11:49:56,160] (root) DEBUG - adding {'config': <__main__.MonitorConfig object at 0x1e24210>, 'target': 'cluster'} to message Message()
  1572. [2017-08-16 11:49:56,160] (root) DEBUG - sending message "Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=cluster)" to "cluster"...
  1573. [2017-08-16 11:49:56,160] (cluster) DEBUG - setting up cluster resources...
  1574. [2017-08-16 11:49:56,160] (cluster) INFO - checking resources (attempt 1 of 3)...
  1575. [2017-08-16 11:49:56,160] (cluster) DEBUG - calling <lambda>...
  1576. [2017-08-16 11:49:56,160] (cluster) DEBUG - updating all information...
  1577. [2017-08-16 11:49:56,160] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1578. [2017-08-16 11:49:56,162] (monit) DEBUG - received message Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=mon)
  1579. [2017-08-16 11:49:56,162] (monit) DEBUG - adding trigger "system/raid" to monitoring ({'action': 'migrate-away', 'identifier': 'raid-failure', 'persistence': 1})
  1580. [2017-08-16 11:49:56,162] (monit) DEBUG - adding trigger "mediamon/log/critical" to monitoring ({'action': 'standby', 'identifier': 'mediamon-critical', 'persistence': 5})
  1581. [2017-08-16 11:49:56,162] (monit) DEBUG - adding trigger "network/network/interface/eth1/status" to monitoring ({'action': 'migrate-away', 'identifier': 'eth1', 'persistence': 1})
  1582. [2017-08-16 11:49:56,163] (monit) DEBUG - adding trigger "sipsecmon/log/critical" to monitoring ({'action': 'standby', 'identifier': 'sipsecmon-critical', 'persistence': 5})
  1583. [2017-08-16 11:49:56,163] (monit) DEBUG - retrieving events ({'minid': 140913})...
  1584. [2017-08-16 11:49:56,173] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1585. [2017-08-16 11:49:56,177] (root) DEBUG - no events on inotify watcher
  1586. [2017-08-16 11:49:56,178] (cluster) DEBUG - update cibmap called (force=True)
  1587. [2017-08-16 11:49:56,191] (cluster) INFO - got 3 resources...
  1588. [2017-08-16 11:49:56,191] (cluster) DEBUG - checking last configuration change...
  1589. [2017-08-16 11:49:56,205] (cluster) DEBUG - calling monitor mainloop...
  1590. [2017-08-16 11:49:56,205] (cluster) DEBUG - received "status" or "config" message, ignoring..
  1591. [2017-08-16 11:49:56,206] (cluster) DEBUG - updating all information...
  1592. [2017-08-16 11:49:56,206] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1593. [2017-08-16 11:49:56,210] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1594. [2017-08-16 11:49:56,215] (root) DEBUG - no events on inotify watcher
  1595. [2017-08-16 11:49:56,215] (cluster) DEBUG - update cibmap called (force=False)
  1596. [2017-08-16 11:49:56,215] (cluster) DEBUG - cib not changed, looping...
  1597. [2017-08-16 11:49:56,709] (monit) INFO - verifying 5 new audit point events...
  1598. [2017-08-16 11:49:56,709] (monit) INFO - not running as master - skipping actions for failover
  1599. [2017-08-16 11:49:58,160] (fs) DEBUG - timeout waiting for messages on queue
  1600. [2017-08-16 11:49:58,160] (fs) DEBUG - fsmainloop receiving message..
  1601. [2017-08-16 11:49:58,215] (cluster) DEBUG - updating all information...
  1602. [2017-08-16 11:49:58,216] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1603. [2017-08-16 11:49:58,221] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1604. [2017-08-16 11:49:58,226] (root) DEBUG - no events on inotify watcher
  1605. [2017-08-16 11:49:58,226] (cluster) DEBUG - update cibmap called (force=True)
  1606. [2017-08-16 11:49:58,239] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1607. [2017-08-16 11:49:58,240] (cluster) INFO - master changed (None => S1-SBC00.e-contact.cl)
  1608. [2017-08-16 11:49:58,240] (root) DEBUG - adding {'status': {'master': False}} to message Message()
  1609. [2017-08-16 11:49:58,240] (root) DEBUG - adding {'status': {'master': False}, 'target': 'led'} to message Message()
  1610. [2017-08-16 11:49:58,240] (root) DEBUG - sending message "Message(status={'master': False}, target=led)" to "led"...
  1611. [2017-08-16 11:49:58,240] (root) DEBUG - adding {'status': {'master': False}, 'target': 'fs'} to message Message()
  1612. [2017-08-16 11:49:58,240] (root) DEBUG - sending message "Message(status={'master': False}, target=fs)" to "fs"...
  1613. [2017-08-16 11:49:58,240] (root) DEBUG - adding {'status': {'master': False}, 'target': 'db'} to message Message()
  1614. [2017-08-16 11:49:58,240] (root) DEBUG - sending message "Message(status={'master': False}, target=db)" to "db"...
  1615. [2017-08-16 11:49:58,240] (root) DEBUG - adding {'status': {'master': False}, 'target': 'mon'} to message Message()
  1616. [2017-08-16 11:49:58,240] (root) DEBUG - sending message "Message(status={'master': False}, target=mon)" to "mon"...
  1617. [2017-08-16 11:49:58,240] (root) DEBUG - adding {'status': {'master': False}, 'target': 'cluster'} to message Message()
  1618. [2017-08-16 11:49:58,240] (root) DEBUG - sending message "Message(status={'master': False}, target=cluster)" to "cluster"...
  1619. [2017-08-16 11:49:58,241] (cluster) DEBUG - file last written = Wed Jun  7 01:52:31 2017
  1620. [2017-08-16 11:49:58,241] (cluster) INFO - running as slave - updating configuration timestamp
  1621. [2017-08-16 11:49:58,241] (cluster) DEBUG - received "status" or "config" message, ignoring..
  1622. [2017-08-16 11:49:58,241] (cluster) DEBUG - updating all information...
  1623. [2017-08-16 11:49:58,241] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1624. [2017-08-16 11:49:58,243] (led-client) INFO - sending status "A" to LED server...
  1625. [2017-08-16 11:49:58,244] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1626. [2017-08-16 11:49:58,249] (root) DEBUG - no events on inotify watcher
  1627. [2017-08-16 11:49:58,249] (cluster) DEBUG - update cibmap called (force=False)
  1628. [2017-08-16 11:49:58,249] (cluster) DEBUG - cib not changed, looping...
  1629. [2017-08-16 11:49:58,274] (fs) DEBUG - received message Message(status={'master': False}, target=fs)
  1630. [2017-08-16 11:49:58,274] (fs) DEBUG - fsmainloop receiving message..
  1631. [2017-08-16 11:49:58,274] (monit) DEBUG - received message Message(status={'master': False}, target=mon)
  1632. [2017-08-16 11:49:58,514] (mariadb) INFO - exited with 0
  1633. [2017-08-16 11:49:58,515] (mariadb) DEBUG - unable to read pidfile: [Errno 2] No such file or directory: '/var/run/mariadb/mariadb.pid'
  1634. [2017-08-16 11:49:58,515] (db) INFO - starting mariadbgalera...
  1635. [2017-08-16 11:49:58,515] (mariadb) DEBUG - asserting path /var/log/mariadb.log (mode = 640, is_dir = False)
  1636. [2017-08-16 11:49:58,515] (mariadb) DEBUG - changing ownership of /var/log/mariadb.log to (27, 27)
  1637. [2017-08-16 11:49:58,515] (mariadb) DEBUG - popener(['/sbin/restorecon', '/var/log/mariadb.log'], {} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1638. [2017-08-16 11:49:58,518] (mariadb) DEBUG - asserting path /var/lib/mariadb (mode = 755, is_dir = True)
  1639. [2017-08-16 11:49:58,518] (mariadb) DEBUG - changing ownership of /var/lib/mariadb to (27, 27)
  1640. [2017-08-16 11:49:58,518] (mariadb) DEBUG - popener(['/sbin/restorecon', '/var/lib/mariadb'], {} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1641. [2017-08-16 11:49:58,522] (mariadb) DEBUG - popener(['/usr/local/sng/bin/sng-spawn-subprocess', '/opt/mariadb-galera/bin/mysqld', '--defaults-file=/etc/mariadb.cnf', '--datadir=/var/lib/mariadb', '--socket=/var/lib/mariadb/mariadb.sock', '--pid-file=/var/run/mariadb/mariadb.pid', '--basedir=/opt/mariadb-galera', '--user=mysql', '--wsrep_recover', '--log_error=/var/lib/mariadb/wsrep_recovery.FjnIcG.log', '--pid-file=/var/lib/mariadb/S1-SBC01.e-contact.cl-recover.pid'], {'cwd': '/opt/mariadb-galera'} - {'stdout': 18, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 20, 'cwd': '/opt/mariadb-galera'})
  1642. [2017-08-16 11:49:58,538] (sngpyutils.io.popener) INFO - mysqld[31560] 170816 11:49:58 [Note] /opt/mariadb-galera/bin/mysqld (mysqld 10.0.23-MariaDB-wsrep-log) starting as process 31561 ...
  1643. [2017-08-16 11:49:59,155] (server) DEBUG - accepting new connection...
  1644. [2017-08-16 11:49:59,156] (request) DEBUG - handling connection from ('127.0.0.1', 46394)
  1645. [2017-08-16 11:49:59,156] (request) DEBUG - received request: ['PING']
  1646. [2017-08-16 11:49:59,156] (request) DEBUG - sending ping to cluster thread...
  1647. [2017-08-16 11:49:59,156] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1648. [2017-08-16 11:49:59,156] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x1e47758>} to message Message(request=ping)
  1649. [2017-08-16 11:49:59,156] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x1e47758>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1650. [2017-08-16 11:49:59,156] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x1e47758>, target=cluster)" to "cluster"...
  1651. [2017-08-16 11:49:59,164] (cluster) DEBUG - updating all information...
  1652. [2017-08-16 11:49:59,164] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 24, 'stdout': 21})
  1653. [2017-08-16 11:49:59,169] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 24, 'stdout': 21})
  1654. [2017-08-16 11:49:59,171] (root) DEBUG - got acknowledge from "cluster"
  1655. [2017-08-16 11:49:59,171] (request) DEBUG - got response from ping: True...
  1656. [2017-08-16 11:49:59,175] (root) DEBUG - no events on inotify watcher
  1657. [2017-08-16 11:49:59,175] (cluster) DEBUG - update cibmap called (force=True)
  1658. [2017-08-16 11:49:59,191] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1659. [2017-08-16 11:50:00,274] (fs) DEBUG - timeout waiting for messages on queue
  1660. [2017-08-16 11:50:00,274] (fs) DEBUG - fsmainloop receiving message..
  1661. [2017-08-16 11:50:00,853] (mariadb) INFO - WSREP: recovered position 75035b86-4b44-11e7-b697-1617bbabffa1:11841
  1662. [2017-08-16 11:50:00,853] (mariadb) DEBUG - popener(['/usr/local/sng/bin/sng-spawn-subprocess', '/opt/mariadb-galera/bin/mysqld', '--defaults-file=/etc/mariadb.cnf', '--datadir=/var/lib/mariadb', '--socket=/var/lib/mariadb/mariadb.sock', '--pid-file=/var/run/mariadb/mariadb.pid', '--basedir=/opt/mariadb-galera', '--user=mysql', '--wsrep_start_position=75035b86-4b44-11e7-b697-1617bbabffa1:11841'], {'cwd': '/opt/mariadb-galera'} - {'stdout': 15, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'cwd': '/opt/mariadb-galera'})
  1663. [2017-08-16 11:50:00,857] (db) DEBUG - received message Message(config=MonitorConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,nodes=[NodeConfig(uuid=76b13887-3a3f-9090-3294-b98aecb98aed,name=S1-SBC00.e-contact.cl,addrs=['10.10.150.2', '172.17.233.36']),NodeConfig(uuid=fd8db308-7450-4aee-2a0c-695b04695b05,name=S1-SBC01.e-contact.cl,addrs=['10.10.150.3', '172.17.233.37'])],options=[primary-bus-addr,secondary-bus-addr,secondary-bus-port,db-port,primary-bus-port,triggers=raid-failure,mediamon-critical,eth1,sipsecmon-critical]), target=db)
  1664. [2017-08-16 11:50:00,858] (db) DEBUG - creating new DB connection...
  1665. [2017-08-16 11:50:00,860] (db) WARNING - unable to connect: Error(('08S01', "[08S01] [unixODBC][MySQL][ODBC 5.1 Driver]Can't connect to local MySQL server through socket '/var/lib/mariadb/mariadb.sock' (111) (2002) (SQLDriverConnect)"))
  1666. [2017-08-16 11:50:00,860] (db) DEBUG - mariadb status: running
  1667. [2017-08-16 11:50:00,860] (db) DEBUG - received message Message(status={'master': False}, target=db)
  1668. [2017-08-16 11:50:00,861] (db) DEBUG - creating new DB connection...
  1669. [2017-08-16 11:50:00,862] (db) DEBUG - looping at addresses "['10.10.150.2', '172.17.233.36']"...
  1670. [2017-08-16 11:50:00,862] (db) DEBUG - adding address "10.10.150.2" (number=0) to list...
  1671. [2017-08-16 11:50:00,863] (db) DEBUG - adding address "172.17.233.36" (number=1) to list...
  1672. [2017-08-16 11:50:00,863] (db) DEBUG - skipping addresses "['10.10.150.3', '172.17.233.37']"...
  1673. [2017-08-16 11:50:00,863] (db) DEBUG - returning addresses ['10.10.150.2', '172.17.233.36']
  1674. [2017-08-16 11:50:00,863] (db) DEBUG - wrote address as "gcomm://10.10.150.2,172.17.233.36", slave mode True, slave cleaning False
  1675. [2017-08-16 11:50:00,863] (db) DEBUG - mariadb status: running
  1676. [2017-08-16 11:50:00,863] (db) INFO - reload pending, restarting service...
  1677. [2017-08-16 11:50:00,863] (db) INFO - stopping mariadbgalera...
  1678. [2017-08-16 11:50:01,191] (cluster) DEBUG - updating all information...
  1679. [2017-08-16 11:50:01,191] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1680. [2017-08-16 11:50:01,196] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1681. [2017-08-16 11:50:01,201] (root) DEBUG - no events on inotify watcher
  1682. [2017-08-16 11:50:01,201] (cluster) DEBUG - update cibmap called (force=False)
  1683. [2017-08-16 11:50:01,201] (cluster) DEBUG - cib not changed, looping...
  1684. [2017-08-16 11:50:01,864] (mariadb) INFO - exited with -15
  1685. [2017-08-16 11:50:01,864] (mariadb) DEBUG - unable to read pidfile: [Errno 2] No such file or directory: '/var/run/mariadb/mariadb.pid'
  1686. [2017-08-16 11:50:01,864] (db) INFO - starting mariadbgalera...
  1687. [2017-08-16 11:50:01,864] (mariadb) DEBUG - asserting path /var/log/mariadb.log (mode = 640, is_dir = False)
  1688. [2017-08-16 11:50:01,864] (mariadb) DEBUG - changing ownership of /var/log/mariadb.log to (27, 27)
  1689. [2017-08-16 11:50:01,865] (mariadb) DEBUG - popener(['/sbin/restorecon', '/var/log/mariadb.log'], {} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1690. [2017-08-16 11:50:01,868] (mariadb) DEBUG - asserting path /var/lib/mariadb (mode = 755, is_dir = True)
  1691. [2017-08-16 11:50:01,869] (mariadb) DEBUG - changing ownership of /var/lib/mariadb to (27, 27)
  1692. [2017-08-16 11:50:01,869] (mariadb) DEBUG - popener(['/sbin/restorecon', '/var/lib/mariadb'], {} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'stdout': 15})
  1693. [2017-08-16 11:50:01,871] (mariadb) DEBUG - popener(['/usr/local/sng/bin/sng-spawn-subprocess', '/opt/mariadb-galera/bin/mysqld', '--defaults-file=/etc/mariadb.cnf', '--datadir=/var/lib/mariadb', '--socket=/var/lib/mariadb/mariadb.sock', '--pid-file=/var/run/mariadb/mariadb.pid', '--basedir=/opt/mariadb-galera', '--user=mysql', '--wsrep_recover', '--log_error=/var/lib/mariadb/wsrep_recovery.03drSr.log', '--pid-file=/var/lib/mariadb/S1-SBC01.e-contact.cl-recover.pid'], {'cwd': '/opt/mariadb-galera'} - {'stdout': 18, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 20, 'cwd': '/opt/mariadb-galera'})
  1694. [2017-08-16 11:50:01,887] (sngpyutils.io.popener) INFO - mysqld[31731] 170816 11:50:01 [Note] /opt/mariadb-galera/bin/mysqld (mysqld 10.0.23-MariaDB-wsrep-log) starting as process 31732 ...
  1695. [2017-08-16 11:50:02,274] (fs) DEBUG - timeout waiting for messages on queue
  1696. [2017-08-16 11:50:02,275] (fs) DEBUG - fsmainloop receiving message..
  1697. [2017-08-16 11:50:03,201] (cluster) DEBUG - updating all information...
  1698. [2017-08-16 11:50:03,202] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1699. [2017-08-16 11:50:03,208] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1700. [2017-08-16 11:50:03,212] (root) DEBUG - no events on inotify watcher
  1701. [2017-08-16 11:50:03,212] (cluster) DEBUG - update cibmap called (force=True)
  1702. [2017-08-16 11:50:03,225] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1703. [2017-08-16 11:50:04,196] (mariadb) INFO - WSREP: recovered position 75035b86-4b44-11e7-b697-1617bbabffa1:11841
  1704. [2017-08-16 11:50:04,196] (mariadb) DEBUG - popener(['/usr/local/sng/bin/sng-spawn-subprocess', '/opt/mariadb-galera/bin/mysqld', '--defaults-file=/etc/mariadb.cnf', '--datadir=/var/lib/mariadb', '--socket=/var/lib/mariadb/mariadb.sock', '--pid-file=/var/run/mariadb/mariadb.pid', '--basedir=/opt/mariadb-galera', '--user=mysql', '--wsrep_start_position=75035b86-4b44-11e7-b697-1617bbabffa1:11841'], {'cwd': '/opt/mariadb-galera'} - {'stdout': 15, 'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 19, 'cwd': '/opt/mariadb-galera'})
  1705. [2017-08-16 11:50:04,214] (sngpyutils.io.popener) INFO - mysqld[31759] 170816 11:50:04 [Note] /opt/mariadb-galera/bin/mysqld (mysqld 10.0.23-MariaDB-wsrep-log) starting as process 31760 ...
  1706. [2017-08-16 11:50:04,275] (fs) DEBUG - timeout waiting for messages on queue
  1707. [2017-08-16 11:50:04,275] (fs) DEBUG - fsmainloop receiving message..
  1708. [2017-08-16 11:50:05,226] (cluster) DEBUG - updating all information...
  1709. [2017-08-16 11:50:05,226] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1710. [2017-08-16 11:50:05,231] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1711. [2017-08-16 11:50:05,236] (root) DEBUG - no events on inotify watcher
  1712. [2017-08-16 11:50:05,236] (cluster) DEBUG - update cibmap called (force=False)
  1713. [2017-08-16 11:50:05,236] (cluster) DEBUG - cib not changed, looping...
  1714. [2017-08-16 11:50:06,275] (fs) DEBUG - timeout waiting for messages on queue
  1715. [2017-08-16 11:50:06,275] (fs) DEBUG - fsmainloop receiving message..
  1716. [2017-08-16 11:50:07,236] (cluster) DEBUG - updating all information...
  1717. [2017-08-16 11:50:07,237] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1718. [2017-08-16 11:50:07,242] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1719. [2017-08-16 11:50:07,247] (root) DEBUG - no events on inotify watcher
  1720. [2017-08-16 11:50:07,247] (cluster) DEBUG - update cibmap called (force=True)
  1721. [2017-08-16 11:50:07,259] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1722. [2017-08-16 11:50:08,199] (db) DEBUG - creating new DB connection...
  1723. [2017-08-16 11:50:08,201] (db) DEBUG - skipping users verification, running in slave mode...
  1724. [2017-08-16 11:50:08,201] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1725. [2017-08-16 11:50:08,202] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1726. [2017-08-16 11:50:08,202] (db) INFO - cluster state UUID set to "75035b86-4b44-11e7-b697-1617bbabffa1"
  1727. [2017-08-16 11:50:08,202] (db) INFO - cluster UUID set to "302083a6-8292-11e7-89b6-cb0e632baabf"
  1728. [2017-08-16 11:50:08,202] (db) INFO - local state set to "Synced"
  1729. [2017-08-16 11:50:08,203] (db) INFO - local state UUID set to "75035b86-4b44-11e7-b697-1617bbabffa1"
  1730. [2017-08-16 11:50:08,203] (db) DEBUG - wsrep_cluster_address: set to "gcomm://10.10.150.2,172.17.233.36"
  1731. [2017-08-16 11:50:08,203] (db) DEBUG - wsrep_evs_state: set to "OPERATIONAL"
  1732. [2017-08-16 11:50:08,203] (db) DEBUG - wsrep_last_committed: set to "12375"
  1733. [2017-08-16 11:50:08,203] (db) INFO - cluster status set to "Primary"
  1734. [2017-08-16 11:50:08,203] (db) INFO - cluster size set to "2"
  1735. [2017-08-16 11:50:08,203] (db) DEBUG - wsrep_incoming_addresses: set to "10.10.150.3:3307,10.10.150.2:3307"
  1736. [2017-08-16 11:50:08,203] (db) DEBUG - closing DB connection...
  1737. [2017-08-16 11:50:08,203] (db) DEBUG - mariadb status: running
  1738. [2017-08-16 11:50:08,275] (fs) DEBUG - timeout waiting for messages on queue
  1739. [2017-08-16 11:50:08,275] (fs) DEBUG - fsmainloop receiving message..
  1740. [2017-08-16 11:50:08,332] (server) DEBUG - accepting new connection...
  1741. [2017-08-16 11:50:08,333] (request) DEBUG - handling connection from ('127.0.0.1', 46404)
  1742. [2017-08-16 11:50:08,333] (request) DEBUG - received request: ['STATUS']
  1743. [2017-08-16 11:50:08,333] (request) DEBUG - querying status from led...
  1744. [2017-08-16 11:50:08,333] (request) DEBUG - querying status from fs...
  1745. [2017-08-16 11:50:08,333] (request) DEBUG - querying status from db...
  1746. [2017-08-16 11:50:08,333] (request) DEBUG - querying status from mon...
  1747. [2017-08-16 11:50:08,333] (request) DEBUG - querying status from cluster...
  1748. [2017-08-16 11:50:09,259] (cluster) DEBUG - updating all information...
  1749. [2017-08-16 11:50:09,260] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1750. [2017-08-16 11:50:09,265] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1751. [2017-08-16 11:50:09,270] (root) DEBUG - WD=(2) MASK=(2) COOKIE=(0) LEN=(0) MASK->NAMES=['IN_MODIFY'] WATCH-PATH=[/var/sngmonit/state] FILENAME=[]
  1752. [2017-08-16 11:50:09,270] (cluster) DEBUG - detected sngmonit update on filesystem
  1753. [2017-08-16 11:50:09,270] (root) DEBUG - adding {'request': 'sngmonit'} to message Message()
  1754. [2017-08-16 11:50:09,270] (root) DEBUG - adding {'request': 'sngmonit', 'target': 'mon'} to message Message()
  1755. [2017-08-16 11:50:09,270] (root) DEBUG - sending message "Message(request=sngmonit, target=mon)" to "mon"...
  1756. [2017-08-16 11:50:09,271] (root) DEBUG - no events on inotify watcher
  1757. [2017-08-16 11:50:09,271] (cluster) DEBUG - update cibmap called (force=False)
  1758. [2017-08-16 11:50:09,271] (cluster) DEBUG - cib not changed, looping...
  1759. [2017-08-16 11:50:09,304] (monit) DEBUG - received message Message(request=sngmonit, target=mon)
  1760. [2017-08-16 11:50:10,276] (fs) DEBUG - timeout waiting for messages on queue
  1761. [2017-08-16 11:50:10,276] (fs) DEBUG - fsmainloop receiving message..
  1762. [2017-08-16 11:50:11,271] (cluster) DEBUG - updating all information...
  1763. [2017-08-16 11:50:11,271] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1764. [2017-08-16 11:50:11,275] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1765. [2017-08-16 11:50:11,281] (root) DEBUG - no events on inotify watcher
  1766. [2017-08-16 11:50:11,281] (cluster) DEBUG - update cibmap called (force=True)
  1767. [2017-08-16 11:50:11,295] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1768. [2017-08-16 11:50:12,204] (db) DEBUG - creating new DB connection...
  1769. [2017-08-16 11:50:12,205] (db) DEBUG - skipping users verification, running in slave mode...
  1770. [2017-08-16 11:50:12,205] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1771. [2017-08-16 11:50:12,206] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1772. [2017-08-16 11:50:12,207] (db) DEBUG - closing DB connection...
  1773. [2017-08-16 11:50:12,207] (db) DEBUG - mariadb status: running
  1774. [2017-08-16 11:50:12,276] (fs) DEBUG - timeout waiting for messages on queue
  1775. [2017-08-16 11:50:12,276] (fs) DEBUG - fsmainloop receiving message..
  1776. [2017-08-16 11:50:13,295] (cluster) DEBUG - updating all information...
  1777. [2017-08-16 11:50:13,295] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1778. [2017-08-16 11:50:13,299] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 21, 'stdout': 19})
  1779. [2017-08-16 11:50:13,304] (root) DEBUG - no events on inotify watcher
  1780. [2017-08-16 11:50:13,305] (cluster) DEBUG - update cibmap called (force=False)
  1781. [2017-08-16 11:50:13,305] (cluster) DEBUG - cib not changed, looping...
  1782. [2017-08-16 11:50:14,277] (fs) DEBUG - timeout waiting for messages on queue
  1783. [2017-08-16 11:50:14,277] (fs) DEBUG - fsmainloop receiving message..
  1784. [2017-08-16 11:50:14,305] (monit) DEBUG - retrieving events ({'minid': 140918})...
  1785. [2017-08-16 11:50:15,305] (cluster) DEBUG - updating all information...
  1786. [2017-08-16 11:50:15,305] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1787. [2017-08-16 11:50:15,311] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1788. [2017-08-16 11:50:15,317] (root) DEBUG - no events on inotify watcher
  1789. [2017-08-16 11:50:15,317] (cluster) DEBUG - update cibmap called (force=True)
  1790. [2017-08-16 11:50:15,333] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1791. [2017-08-16 11:50:16,207] (db) DEBUG - creating new DB connection...
  1792. [2017-08-16 11:50:16,208] (db) DEBUG - skipping users verification, running in slave mode...
  1793. [2017-08-16 11:50:16,209] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1794. [2017-08-16 11:50:16,209] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1795. [2017-08-16 11:50:16,210] (db) DEBUG - closing DB connection...
  1796. [2017-08-16 11:50:16,210] (db) DEBUG - mariadb status: running
  1797. [2017-08-16 11:50:16,277] (fs) DEBUG - timeout waiting for messages on queue
  1798. [2017-08-16 11:50:16,277] (fs) DEBUG - fsmainloop receiving message..
  1799. [2017-08-16 11:50:17,333] (cluster) DEBUG - updating all information...
  1800. [2017-08-16 11:50:17,333] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1801. [2017-08-16 11:50:17,339] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1802. [2017-08-16 11:50:17,344] (root) DEBUG - no events on inotify watcher
  1803. [2017-08-16 11:50:17,344] (cluster) DEBUG - update cibmap called (force=False)
  1804. [2017-08-16 11:50:17,344] (cluster) DEBUG - cib not changed, looping...
  1805. [2017-08-16 11:50:18,277] (fs) DEBUG - timeout waiting for messages on queue
  1806. [2017-08-16 11:50:18,277] (fs) DEBUG - fsmainloop receiving message..
  1807. [2017-08-16 11:50:19,344] (cluster) DEBUG - updating all information...
  1808. [2017-08-16 11:50:19,345] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1809. [2017-08-16 11:50:19,348] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1810. [2017-08-16 11:50:19,353] (root) DEBUG - no events on inotify watcher
  1811. [2017-08-16 11:50:19,354] (cluster) DEBUG - update cibmap called (force=True)
  1812. [2017-08-16 11:50:19,367] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1813. [2017-08-16 11:50:19,513] (server) DEBUG - accepting new connection...
  1814. [2017-08-16 11:50:19,513] (request) DEBUG - handling connection from ('127.0.0.1', 46416)
  1815. [2017-08-16 11:50:19,513] (request) DEBUG - received request: ['PING']
  1816. [2017-08-16 11:50:19,513] (request) DEBUG - sending ping to cluster thread...
  1817. [2017-08-16 11:50:19,514] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1818. [2017-08-16 11:50:19,514] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x7f98d9118290>} to message Message(request=ping)
  1819. [2017-08-16 11:50:19,514] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x7f98d9118290>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1820. [2017-08-16 11:50:19,514] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x7f98d9118290>, target=cluster)" to "cluster"...
  1821. [2017-08-16 11:50:19,531] (cluster) DEBUG - updating all information...
  1822. [2017-08-16 11:50:19,531] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 23, 'stdout': 21})
  1823. [2017-08-16 11:50:19,536] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 23, 'stdout': 21})
  1824. [2017-08-16 11:50:19,541] (root) DEBUG - no events on inotify watcher
  1825. [2017-08-16 11:50:19,541] (cluster) DEBUG - update cibmap called (force=False)
  1826. [2017-08-16 11:50:19,541] (cluster) DEBUG - cib not changed, looping...
  1827. [2017-08-16 11:50:19,545] (root) DEBUG - got acknowledge from "cluster"
  1828. [2017-08-16 11:50:19,545] (request) DEBUG - got response from ping: True...
  1829. [2017-08-16 11:50:20,210] (db) DEBUG - creating new DB connection...
  1830. [2017-08-16 11:50:20,211] (db) DEBUG - skipping users verification, running in slave mode...
  1831. [2017-08-16 11:50:20,211] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1832. [2017-08-16 11:50:20,212] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1833. [2017-08-16 11:50:20,213] (db) DEBUG - closing DB connection...
  1834. [2017-08-16 11:50:20,213] (db) DEBUG - mariadb status: running
  1835. [2017-08-16 11:50:20,278] (fs) DEBUG - timeout waiting for messages on queue
  1836. [2017-08-16 11:50:20,278] (fs) DEBUG - fsmainloop receiving message..
  1837. [2017-08-16 11:50:21,541] (cluster) DEBUG - updating all information...
  1838. [2017-08-16 11:50:21,541] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1839. [2017-08-16 11:50:21,547] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1840. [2017-08-16 11:50:21,552] (root) DEBUG - no events on inotify watcher
  1841. [2017-08-16 11:50:21,552] (cluster) DEBUG - update cibmap called (force=True)
  1842. [2017-08-16 11:50:21,566] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1843. [2017-08-16 11:50:22,278] (fs) DEBUG - timeout waiting for messages on queue
  1844. [2017-08-16 11:50:22,278] (fs) DEBUG - fsmainloop receiving message..
  1845. [2017-08-16 11:50:23,566] (cluster) DEBUG - updating all information...
  1846. [2017-08-16 11:50:23,566] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1847. [2017-08-16 11:50:23,570] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1848. [2017-08-16 11:50:23,576] (root) DEBUG - no events on inotify watcher
  1849. [2017-08-16 11:50:23,576] (cluster) DEBUG - update cibmap called (force=False)
  1850. [2017-08-16 11:50:23,576] (cluster) DEBUG - cib not changed, looping...
  1851. [2017-08-16 11:50:24,213] (db) DEBUG - creating new DB connection...
  1852. [2017-08-16 11:50:24,214] (db) DEBUG - skipping users verification, running in slave mode...
  1853. [2017-08-16 11:50:24,214] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1854. [2017-08-16 11:50:24,215] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1855. [2017-08-16 11:50:24,216] (db) DEBUG - closing DB connection...
  1856. [2017-08-16 11:50:24,216] (db) DEBUG - mariadb status: running
  1857. [2017-08-16 11:50:24,278] (fs) DEBUG - timeout waiting for messages on queue
  1858. [2017-08-16 11:50:24,278] (fs) DEBUG - fsmainloop receiving message..
  1859. [2017-08-16 11:50:25,576] (cluster) DEBUG - updating all information...
  1860. [2017-08-16 11:50:25,576] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1861. [2017-08-16 11:50:25,581] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1862. [2017-08-16 11:50:25,586] (root) DEBUG - no events on inotify watcher
  1863. [2017-08-16 11:50:25,586] (cluster) DEBUG - update cibmap called (force=True)
  1864. [2017-08-16 11:50:25,599] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1865. [2017-08-16 11:50:26,279] (fs) DEBUG - timeout waiting for messages on queue
  1866. [2017-08-16 11:50:26,279] (fs) DEBUG - fsmainloop receiving message..
  1867. [2017-08-16 11:50:27,600] (cluster) DEBUG - updating all information...
  1868. [2017-08-16 11:50:27,600] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1869. [2017-08-16 11:50:27,604] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1870. [2017-08-16 11:50:27,609] (root) DEBUG - no events on inotify watcher
  1871. [2017-08-16 11:50:27,609] (cluster) DEBUG - update cibmap called (force=False)
  1872. [2017-08-16 11:50:27,609] (cluster) DEBUG - cib not changed, looping...
  1873. [2017-08-16 11:50:28,216] (db) DEBUG - creating new DB connection...
  1874. [2017-08-16 11:50:28,217] (db) DEBUG - skipping users verification, running in slave mode...
  1875. [2017-08-16 11:50:28,217] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1876. [2017-08-16 11:50:28,218] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1877. [2017-08-16 11:50:28,219] (db) DEBUG - closing DB connection...
  1878. [2017-08-16 11:50:28,219] (db) DEBUG - mariadb status: running
  1879. [2017-08-16 11:50:28,279] (fs) DEBUG - timeout waiting for messages on queue
  1880. [2017-08-16 11:50:28,279] (fs) DEBUG - fsmainloop receiving message..
  1881. [2017-08-16 11:50:28,352] (server) DEBUG - accepting new connection...
  1882. [2017-08-16 11:50:28,352] (request) DEBUG - handling connection from ('127.0.0.1', 46424)
  1883. [2017-08-16 11:50:28,352] (request) DEBUG - received request: ['STATUS']
  1884. [2017-08-16 11:50:28,353] (request) DEBUG - querying status from led...
  1885. [2017-08-16 11:50:28,353] (request) DEBUG - querying status from fs...
  1886. [2017-08-16 11:50:28,353] (request) DEBUG - querying status from db...
  1887. [2017-08-16 11:50:28,353] (request) DEBUG - querying status from mon...
  1888. [2017-08-16 11:50:28,353] (request) DEBUG - querying status from cluster...
  1889. [2017-08-16 11:50:29,609] (cluster) DEBUG - updating all information...
  1890. [2017-08-16 11:50:29,610] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1891. [2017-08-16 11:50:29,616] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1892. [2017-08-16 11:50:29,621] (root) DEBUG - WD=(2) MASK=(2) COOKIE=(0) LEN=(0) MASK->NAMES=['IN_MODIFY'] WATCH-PATH=[/var/sngmonit/state] FILENAME=[]
  1893. [2017-08-16 11:50:29,621] (cluster) DEBUG - detected sngmonit update on filesystem
  1894. [2017-08-16 11:50:29,621] (root) DEBUG - adding {'request': 'sngmonit'} to message Message()
  1895. [2017-08-16 11:50:29,621] (root) DEBUG - adding {'request': 'sngmonit', 'target': 'mon'} to message Message()
  1896. [2017-08-16 11:50:29,621] (root) DEBUG - sending message "Message(request=sngmonit, target=mon)" to "mon"...
  1897. [2017-08-16 11:50:29,621] (root) DEBUG - no events on inotify watcher
  1898. [2017-08-16 11:50:29,621] (cluster) DEBUG - update cibmap called (force=True)
  1899. [2017-08-16 11:50:29,637] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1900. [2017-08-16 11:50:29,638] (monit) DEBUG - received message Message(request=sngmonit, target=mon)
  1901. [2017-08-16 11:50:30,279] (fs) DEBUG - timeout waiting for messages on queue
  1902. [2017-08-16 11:50:30,280] (fs) DEBUG - fsmainloop receiving message..
  1903. [2017-08-16 11:50:31,637] (cluster) DEBUG - updating all information...
  1904. [2017-08-16 11:50:31,638] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1905. [2017-08-16 11:50:31,642] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1906. [2017-08-16 11:50:31,648] (root) DEBUG - no events on inotify watcher
  1907. [2017-08-16 11:50:31,648] (cluster) DEBUG - update cibmap called (force=False)
  1908. [2017-08-16 11:50:31,648] (cluster) DEBUG - cib not changed, looping...
  1909. [2017-08-16 11:50:32,219] (db) DEBUG - creating new DB connection...
  1910. [2017-08-16 11:50:32,220] (db) DEBUG - skipping users verification, running in slave mode...
  1911. [2017-08-16 11:50:32,221] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1912. [2017-08-16 11:50:32,221] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1913. [2017-08-16 11:50:32,222] (db) DEBUG - closing DB connection...
  1914. [2017-08-16 11:50:32,222] (db) DEBUG - mariadb status: running
  1915. [2017-08-16 11:50:32,280] (fs) DEBUG - timeout waiting for messages on queue
  1916. [2017-08-16 11:50:32,280] (fs) DEBUG - fsmainloop receiving message..
  1917. [2017-08-16 11:50:33,648] (cluster) DEBUG - updating all information...
  1918. [2017-08-16 11:50:33,648] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1919. [2017-08-16 11:50:33,652] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1920. [2017-08-16 11:50:33,657] (root) DEBUG - no events on inotify watcher
  1921. [2017-08-16 11:50:33,657] (cluster) DEBUG - update cibmap called (force=True)
  1922. [2017-08-16 11:50:33,670] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1923. [2017-08-16 11:50:34,280] (fs) DEBUG - timeout waiting for messages on queue
  1924. [2017-08-16 11:50:34,280] (fs) DEBUG - fsmainloop receiving message..
  1925. [2017-08-16 11:50:34,638] (monit) DEBUG - retrieving events ({'minid': 140918})...
  1926. [2017-08-16 11:50:35,671] (cluster) DEBUG - updating all information...
  1927. [2017-08-16 11:50:35,671] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1928. [2017-08-16 11:50:35,677] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1929. [2017-08-16 11:50:35,682] (root) DEBUG - no events on inotify watcher
  1930. [2017-08-16 11:50:35,682] (cluster) DEBUG - update cibmap called (force=False)
  1931. [2017-08-16 11:50:35,682] (cluster) DEBUG - cib not changed, looping...
  1932. [2017-08-16 11:50:36,223] (db) DEBUG - creating new DB connection...
  1933. [2017-08-16 11:50:36,224] (db) DEBUG - skipping users verification, running in slave mode...
  1934. [2017-08-16 11:50:36,224] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1935. [2017-08-16 11:50:36,225] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1936. [2017-08-16 11:50:36,225] (db) DEBUG - closing DB connection...
  1937. [2017-08-16 11:50:36,226] (db) DEBUG - mariadb status: running
  1938. [2017-08-16 11:50:36,281] (fs) DEBUG - timeout waiting for messages on queue
  1939. [2017-08-16 11:50:36,281] (fs) DEBUG - fsmainloop receiving message..
  1940. [2017-08-16 11:50:37,682] (cluster) DEBUG - updating all information...
  1941. [2017-08-16 11:50:37,683] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1942. [2017-08-16 11:50:37,687] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1943. [2017-08-16 11:50:37,692] (root) DEBUG - no events on inotify watcher
  1944. [2017-08-16 11:50:37,692] (cluster) DEBUG - update cibmap called (force=True)
  1945. [2017-08-16 11:50:37,706] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1946. [2017-08-16 11:50:38,281] (fs) DEBUG - timeout waiting for messages on queue
  1947. [2017-08-16 11:50:38,281] (fs) DEBUG - fsmainloop receiving message..
  1948. [2017-08-16 11:50:39,514] (server) DEBUG - accepting new connection...
  1949. [2017-08-16 11:50:39,514] (request) DEBUG - handling connection from ('127.0.0.1', 46432)
  1950. [2017-08-16 11:50:39,514] (request) DEBUG - received request: ['PING']
  1951. [2017-08-16 11:50:39,514] (request) DEBUG - sending ping to cluster thread...
  1952. [2017-08-16 11:50:39,514] (root) DEBUG - adding {'request': 'ping'} to message Message()
  1953. [2017-08-16 11:50:39,514] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x1ee3b90>} to message Message(request=ping)
  1954. [2017-08-16 11:50:39,514] (root) DEBUG - adding {'done': <Queue.Queue instance at 0x1ee3b90>, 'request': 'ping', 'target': 'cluster'} to message Message()
  1955. [2017-08-16 11:50:39,514] (root) DEBUG - sending message "Message(request=ping, done=<Queue.Queue instance at 0x1ee3b90>, target=cluster)" to "cluster"...
  1956. [2017-08-16 11:50:39,522] (cluster) DEBUG - updating all information...
  1957. [2017-08-16 11:50:39,523] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 23, 'stdout': 21})
  1958. [2017-08-16 11:50:39,528] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 23, 'stdout': 21})
  1959. [2017-08-16 11:50:39,530] (root) DEBUG - got acknowledge from "cluster"
  1960. [2017-08-16 11:50:39,530] (request) DEBUG - got response from ping: True...
  1961. [2017-08-16 11:50:39,533] (root) DEBUG - no events on inotify watcher
  1962. [2017-08-16 11:50:39,533] (cluster) DEBUG - update cibmap called (force=False)
  1963. [2017-08-16 11:50:39,533] (cluster) DEBUG - cib not changed, looping...
  1964. [2017-08-16 11:50:40,226] (db) DEBUG - creating new DB connection...
  1965. [2017-08-16 11:50:40,227] (db) DEBUG - skipping users verification, running in slave mode...
  1966. [2017-08-16 11:50:40,227] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1967. [2017-08-16 11:50:40,228] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1968. [2017-08-16 11:50:40,228] (db) DEBUG - closing DB connection...
  1969. [2017-08-16 11:50:40,228] (db) DEBUG - mariadb status: running
  1970. [2017-08-16 11:50:40,281] (fs) DEBUG - timeout waiting for messages on queue
  1971. [2017-08-16 11:50:40,282] (fs) DEBUG - fsmainloop receiving message..
  1972. [2017-08-16 11:50:41,533] (cluster) DEBUG - updating all information...
  1973. [2017-08-16 11:50:41,534] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1974. [2017-08-16 11:50:41,538] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1975. [2017-08-16 11:50:41,543] (root) DEBUG - no events on inotify watcher
  1976. [2017-08-16 11:50:41,543] (cluster) DEBUG - update cibmap called (force=True)
  1977. [2017-08-16 11:50:41,560] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  1978. [2017-08-16 11:50:42,282] (fs) DEBUG - timeout waiting for messages on queue
  1979. [2017-08-16 11:50:42,282] (fs) DEBUG - fsmainloop receiving message..
  1980. [2017-08-16 11:50:43,560] (cluster) DEBUG - updating all information...
  1981. [2017-08-16 11:50:43,560] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1982. [2017-08-16 11:50:43,564] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1983. [2017-08-16 11:50:43,569] (root) DEBUG - no events on inotify watcher
  1984. [2017-08-16 11:50:43,570] (cluster) DEBUG - update cibmap called (force=False)
  1985. [2017-08-16 11:50:43,570] (cluster) DEBUG - cib not changed, looping...
  1986. [2017-08-16 11:50:44,229] (db) DEBUG - creating new DB connection...
  1987. [2017-08-16 11:50:44,230] (db) DEBUG - skipping users verification, running in slave mode...
  1988. [2017-08-16 11:50:44,230] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  1989. [2017-08-16 11:50:44,231] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  1990. [2017-08-16 11:50:44,231] (db) DEBUG - closing DB connection...
  1991. [2017-08-16 11:50:44,232] (db) DEBUG - mariadb status: running
  1992. [2017-08-16 11:50:44,282] (fs) DEBUG - timeout waiting for messages on queue
  1993. [2017-08-16 11:50:44,282] (fs) DEBUG - fsmainloop receiving message..
  1994. [2017-08-16 11:50:45,570] (cluster) DEBUG - updating all information...
  1995. [2017-08-16 11:50:45,570] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1996. [2017-08-16 11:50:45,574] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  1997. [2017-08-16 11:50:45,579] (root) DEBUG - no events on inotify watcher
  1998. [2017-08-16 11:50:45,579] (cluster) DEBUG - update cibmap called (force=True)
  1999. [2017-08-16 11:50:45,610] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  2000. [2017-08-16 11:50:46,282] (fs) DEBUG - timeout waiting for messages on queue
  2001. [2017-08-16 11:50:46,283] (fs) DEBUG - fsmainloop receiving message..
  2002. [2017-08-16 11:50:47,610] (cluster) DEBUG - updating all information...
  2003. [2017-08-16 11:50:47,610] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2004. [2017-08-16 11:50:47,616] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2005. [2017-08-16 11:50:47,622] (root) DEBUG - no events on inotify watcher
  2006. [2017-08-16 11:50:47,622] (cluster) DEBUG - update cibmap called (force=False)
  2007. [2017-08-16 11:50:47,622] (cluster) DEBUG - cib not changed, looping...
  2008. [2017-08-16 11:50:48,232] (db) DEBUG - creating new DB connection...
  2009. [2017-08-16 11:50:48,233] (db) DEBUG - skipping users verification, running in slave mode...
  2010. [2017-08-16 11:50:48,233] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  2011. [2017-08-16 11:50:48,234] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  2012. [2017-08-16 11:50:48,235] (db) DEBUG - closing DB connection...
  2013. [2017-08-16 11:50:48,235] (db) DEBUG - mariadb status: running
  2014. [2017-08-16 11:50:48,283] (fs) DEBUG - timeout waiting for messages on queue
  2015. [2017-08-16 11:50:48,283] (fs) DEBUG - fsmainloop receiving message..
  2016. [2017-08-16 11:50:48,369] (server) DEBUG - accepting new connection...
  2017. [2017-08-16 11:50:48,369] (request) DEBUG - handling connection from ('127.0.0.1', 46440)
  2018. [2017-08-16 11:50:48,369] (request) DEBUG - received request: ['STATUS']
  2019. [2017-08-16 11:50:48,369] (request) DEBUG - querying status from led...
  2020. [2017-08-16 11:50:48,369] (request) DEBUG - querying status from fs...
  2021. [2017-08-16 11:50:48,369] (request) DEBUG - querying status from db...
  2022. [2017-08-16 11:50:48,369] (request) DEBUG - querying status from mon...
  2023. [2017-08-16 11:50:48,370] (request) DEBUG - querying status from cluster...
  2024. [2017-08-16 11:50:49,622] (cluster) DEBUG - updating all information...
  2025. [2017-08-16 11:50:49,622] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2026. [2017-08-16 11:50:49,628] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2027. [2017-08-16 11:50:49,633] (root) DEBUG - WD=(2) MASK=(2) COOKIE=(0) LEN=(0) MASK->NAMES=['IN_MODIFY'] WATCH-PATH=[/var/sngmonit/state] FILENAME=[]
  2028. [2017-08-16 11:50:49,633] (cluster) DEBUG - detected sngmonit update on filesystem
  2029. [2017-08-16 11:50:49,634] (root) DEBUG - adding {'request': 'sngmonit'} to message Message()
  2030. [2017-08-16 11:50:49,634] (root) DEBUG - adding {'request': 'sngmonit', 'target': 'mon'} to message Message()
  2031. [2017-08-16 11:50:49,634] (root) DEBUG - sending message "Message(request=sngmonit, target=mon)" to "mon"...
  2032. [2017-08-16 11:50:49,634] (root) DEBUG - no events on inotify watcher
  2033. [2017-08-16 11:50:49,634] (cluster) DEBUG - update cibmap called (force=True)
  2034. [2017-08-16 11:50:49,647] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  2035. [2017-08-16 11:50:49,671] (monit) DEBUG - received message Message(request=sngmonit, target=mon)
  2036. [2017-08-16 11:50:50,283] (fs) DEBUG - timeout waiting for messages on queue
  2037. [2017-08-16 11:50:50,283] (fs) DEBUG - fsmainloop receiving message..
  2038. [2017-08-16 11:50:51,647] (cluster) DEBUG - updating all information...
  2039. [2017-08-16 11:50:51,647] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2040. [2017-08-16 11:50:51,652] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2041. [2017-08-16 11:50:51,657] (root) DEBUG - no events on inotify watcher
  2042. [2017-08-16 11:50:51,657] (cluster) DEBUG - update cibmap called (force=False)
  2043. [2017-08-16 11:50:51,657] (cluster) DEBUG - cib not changed, looping...
  2044. [2017-08-16 11:50:52,235] (db) DEBUG - creating new DB connection...
  2045. [2017-08-16 11:50:52,236] (db) DEBUG - skipping users verification, running in slave mode...
  2046. [2017-08-16 11:50:52,237] (db) DEBUG - <SQL> SHOW GLOBAL STATUS WHERE Variable_Name IN ('wsrep_gcomm_uuid','wsrep_evs_state','wsrep_last_committed','wsrep_local_state_uuid','wsrep_local_state_comment','wsrep_cluster_state_uuid','wsrep_cluster_status','wsrep_cluster_size','wsrep_incoming_addresses')
  2047. [2017-08-16 11:50:52,237] (db) DEBUG - <SQL> SHOW GLOBAL VARIABLES WHERE Variable_Name IN ('wsrep_cluster_address')
  2048. [2017-08-16 11:50:52,238] (db) DEBUG - closing DB connection...
  2049. [2017-08-16 11:50:52,238] (db) DEBUG - mariadb status: running
  2050. [2017-08-16 11:50:52,283] (fs) DEBUG - timeout waiting for messages on queue
  2051. [2017-08-16 11:50:52,284] (fs) DEBUG - fsmainloop receiving message..
  2052. [2017-08-16 11:50:53,657] (cluster) DEBUG - updating all information...
  2053. [2017-08-16 11:50:53,658] (cluster) DEBUG - popener(['cman_tool', 'status'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2054. [2017-08-16 11:50:53,661] (cluster) DEBUG - popener(['corosync-cfgtool', '-s'], {'stdout': -1} - {'close_fds': True, 'stdin': <open file '/dev/null', mode 'r' at 0x1c10270>, 'stderr': 22, 'stdout': 20})
  2055. [2017-08-16 11:50:53,666] (root) DEBUG - no events on inotify watcher
  2056. [2017-08-16 11:50:53,666] (cluster) DEBUG - update cibmap called (force=True)
  2057. [2017-08-16 11:50:53,680] (cluster) DEBUG - got master node S1-SBC00.e-contact.cl
  2058. [2017-08-16 11:50:54,284] (fs) DEBUG - timeout waiting for messages on queue
  2059. [2017-08-16 11:50:54,284] (fs) DEBUG - fsmainloop receiving message..

Reply to "Monitor"

Here you can reply to the paste above