API tools faq
paste
Advertisement
fedorm

Untitled

fedorm
Aug 9th, 2019
231
0
Never
Add comment
Not a member of Pastebin yet? Sign Up, it unlocks many cool features!
XML 149.04 KB | None | 0 0
raw download clone embed print report
  1. 08.08 20:47:05.604 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  2. 08.08 20:47:05.805 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  3. 08.08 20:47:06.005 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  4. 08.08 20:47:06.205 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  5. 08.08 20:47:06.406 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  6. 08.08 20:47:06.606 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  7. 08.08 20:47:06.806 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  8. 08.08 20:47:07.007 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  9. 08.08 20:50:09.907 DEBUG [TechProcessImpl] Server online mode
  10. 08.08 20:50:09.903 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
  11. 08.08 20:50:09.894 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
  12. 08.08 20:50:12.359 ERROR [TransactionHandler]
  13. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 203140ms.
  14.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  15.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  16.     at com.sun.proxy.$Proxy213.saveOrUpdate(Unknown Source)
  17.     at ru.crystals.pos.loyal.SetApiLoyFeedbackProcessor.scheduleFeedback(SetApiLoyFeedbackProcessor.java:130)
  18.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.lambda$purchaseFiscalized$1(SetApiPluginLoyProvider.java:404)
  19.     at java.util.ArrayList.forEach(ArrayList.java:1249)
  20.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.purchaseFiscalized(SetApiPluginLoyProvider.java:404)
  21.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.purchaseFiscalized(LoyProvidersRegistryImpl.java:362)
  22.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.purchaseFiscalized(LoyalServiceImpl.java:1547)
  23.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.purchaseFiscalized(LoyalBridgeServiceImpl.java:189)
  24.     at ru.crystals.pos.techprocess.ExternalProcessingsImpl.purchaseFiscalized(ExternalProcessingsImpl.java:212)
  25.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1793)
  26.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  27.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeReturnCheck(TechProcessShiftProxy.java:718)
  28.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:698)
  29.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  30.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  31.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  32.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  33.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  34.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  35.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  36.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  37.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  38.     at ru.crystals.pos.visualization.payments.cash.CashPaymentContainer.enter(CashPaymentContainer.java:94)
  39.     at ru.crystals.pos.visualization.components.CompositeContainer.enter(CompositeContainer.java:97)
  40.     at ru.crystals.pos.visualization.check.CheckContainer.enter(CheckContainer.java:1920)
  41.     at ru.crystals.pos.visualization.components.MainWindow.enter(MainWindow.java:1086)
  42.     at ru.crystals.pos.visualization.Factory.eventControlKey(Factory.java:536)
  43.     at ru.crystals.pos.techprocess.TechProcessImpl.eventControlKey(TechProcessImpl.java:4355)
  44.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:167)
  45.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  46.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  47.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  48.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  49.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  50.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  51.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  52.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  53.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  54.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  55.     at java.lang.Thread.run(Thread.java:745)
  56. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 203140ms.
  57.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  58.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  59.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  60.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  61.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  62.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  63.     ... 41 more
  64. 08.08 20:50:12.546 ERROR [TransactionHandler]
  65. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 205403ms.
  66.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  67.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  68.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  69.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  70.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  71.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  72.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  73.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  74.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  75.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  76.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  77.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  78.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  79.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  80.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  81.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  82.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  83.     at java.lang.Thread.run(Thread.java:745)
  84. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 205403ms.
  85.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  86.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  87.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  88.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  89.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  90.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  91.     ... 17 more
  92. 08.08 20:50:12.398 INFO  [PendingOperationQueue] No pending card operations found.
  93. 08.08 20:50:13.672 ERROR [JDBCMapperImpl] Cannot rollback transaction
  94. java.lang.NullPointerException
  95.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  96.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  97.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  98.     at com.sun.proxy.$Proxy213.saveOrUpdate(Unknown Source)
  99.     at ru.crystals.pos.loyal.SetApiLoyFeedbackProcessor.scheduleFeedback(SetApiLoyFeedbackProcessor.java:130)
  100.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.lambda$purchaseFiscalized$1(SetApiPluginLoyProvider.java:404)
  101.     at java.util.ArrayList.forEach(ArrayList.java:1249)
  102.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.purchaseFiscalized(SetApiPluginLoyProvider.java:404)
  103.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.purchaseFiscalized(LoyProvidersRegistryImpl.java:362)
  104.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.purchaseFiscalized(LoyalServiceImpl.java:1547)
  105.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.purchaseFiscalized(LoyalBridgeServiceImpl.java:189)
  106.     at ru.crystals.pos.techprocess.ExternalProcessingsImpl.purchaseFiscalized(ExternalProcessingsImpl.java:212)
  107.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1793)
  108.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  109.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeReturnCheck(TechProcessShiftProxy.java:718)
  110.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:698)
  111.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  112.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  113.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  114.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  115.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  116.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  117.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  118.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  119.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  120.     at ru.crystals.pos.visualization.payments.cash.CashPaymentContainer.enter(CashPaymentContainer.java:94)
  121.     at ru.crystals.pos.visualization.components.CompositeContainer.enter(CompositeContainer.java:97)
  122.     at ru.crystals.pos.visualization.check.CheckContainer.enter(CheckContainer.java:1920)
  123.     at ru.crystals.pos.visualization.components.MainWindow.enter(MainWindow.java:1086)
  124.     at ru.crystals.pos.visualization.Factory.eventControlKey(Factory.java:536)
  125.     at ru.crystals.pos.techprocess.TechProcessImpl.eventControlKey(TechProcessImpl.java:4355)
  126.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:167)
  127.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  128.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  129.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  130.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  131.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  132.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  133.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  134.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  135.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  136.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  137.     at java.lang.Thread.run(Thread.java:745)
  138. 08.08 20:50:13.804 ERROR [JDBCMapperImpl] Cannot rollback transaction
  139. java.lang.NullPointerException
  140.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  141.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  142.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  143.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  144.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  145.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  146.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  147.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  148.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  149.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  150.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  151.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  152.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  153.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  154.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  155.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  156.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  157.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  158.     at java.lang.Thread.run(Thread.java:745)
  159. 08.08 20:50:13.804 ERROR [TransferManager] Error during sending transactions, java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 205403ms.
  160. 08.08 20:50:13.889 INFO  [HttpClient] Set url - http://172.29.17.49:8090/SetXRMI/TransportServlet
  161. 08.08 20:50:15.662 INFO  [LoyProvidersRegistryImpl] Resend stale feedback
  162. 08.08 20:50:19.577 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = ml
  163. 08.08 20:50:15.424 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:50:15 will be deleted.
  164. 08.08 20:50:20.479 INFO  [CashConfigurationUpdateChecker] Received patches list: []
  165. 08.08 20:50:26.168 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
  166. 08.08 20:50:26.168 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  167. 08.08 20:50:27.325 INFO  [DocumentSender] ping = true
  168. 08.08 20:50:27.239 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  169. 08.08 20:50:31.557 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  170.     Id: MQ==
  171.     Date: 2019-08-08 17:23:57.926
  172. 08.08 20:50:31.557 TRACE [MLServiceImpl] entering getServices()
  173. 08.08 20:50:31.557 TRACE [MLServiceImpl] getting services (IN MEMORY)
  174. 08.08 20:50:31.557 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  175. 08.08 20:50:32.113 TRACE [MLServiceImpl] Going to send DissociatingCard:
  176. 08.08 20:50:31.554 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1749,"cash":61,"mode":47,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":37,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":-830.1,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 20:50:20.808","offline":false}]}
  177. 08.08 20:50:32.820 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  178. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  179.     <request>
  180.         <ClientTransactionId>1</ClientTransactionId>
  181.         <Organization>Victoria</Organization>
  182.         <BusinessUnit>1749</BusinessUnit>
  183.         <POS>61</POS>
  184.         <CardNumber>99990002</CardNumber>
  185.         <DateTime>2019-08-08T20:50:32.113+03:00</DateTime>
  186.     </request>
  187. </DissociatingCard>
  188.  
  189. 08.08 20:50:40.360 INFO  [CommonLogger] Cleaning done.
  190. 08.08 20:50:40.361 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:50:40 will be deleted.
  191. 08.08 20:50:40.342 DEBUG [TechProcessImpl] Server online mode
  192. 08.08 20:50:45.189 INFO  [CommonLogger] Cleaning done.
  193. 08.08 20:50:45.190 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:50:45 will be deleted.
  194. 08.08 20:50:45.466 INFO  [CommonLogger] Cleaning done.
  195. 08.08 20:50:45.510 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:50:45 will be deleted.
  196. 08.08 20:50:45.516 INFO  [CommonLogger] Cleaning done.
  197. 08.08 20:50:51.819 ERROR [TransactionHandler]
  198. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 32241ms.
  199.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  200.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  201.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  202.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  203.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  204.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  205.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  206.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  207.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  208.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  209.     at java.lang.Thread.run(Thread.java:745)
  210. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 32241ms.
  211.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  212.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  213.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  214.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  215.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  216.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  217.     ... 10 more
  218. 08.08 20:50:51.819 ERROR [JDBCMapperImpl] Cannot rollback transaction
  219. java.lang.NullPointerException
  220.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  221.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  222.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  223.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  224.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  225.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  226.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  227.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  228.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  229.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  230.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  231.     at java.lang.Thread.run(Thread.java:745)
  232. 08.08 20:50:52.119 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  233. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 32241ms.
  234.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  235.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  236.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  237.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  238.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  239.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  240.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  241.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  242.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  243.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  244.     at java.lang.Thread.run(Thread.java:745)
  245. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 32241ms.
  246.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  247.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  248.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  249.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  250.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  251.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  252.     ... 10 more
  253. 08.08 20:50:52.328 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = smch
  254. 08.08 20:50:56.609 TRACE [MLServiceImpl] entering isEnabled()
  255. 08.08 20:50:56.630 TRACE [MLServiceImpl] leaving isEnabled(). the result is: false
  256. 08.08 20:50:56.630 TRACE [SCService] entering isEnabled()
  257. 08.08 20:50:56.774 TRACE [SCService] leaving isEnabled(). the result is: true
  258. 08.08 20:50:58.428 ERROR [CheckService] java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 203140ms.
  259. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 203140ms.
  260.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  261.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  262.     at com.sun.proxy.$Proxy213.saveOrUpdate(Unknown Source)
  263.     at ru.crystals.pos.loyal.SetApiLoyFeedbackProcessor.scheduleFeedback(SetApiLoyFeedbackProcessor.java:130)
  264.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.lambda$purchaseFiscalized$1(SetApiPluginLoyProvider.java:404)
  265.     at java.util.ArrayList.forEach(ArrayList.java:1249)
  266.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.purchaseFiscalized(SetApiPluginLoyProvider.java:404)
  267.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.purchaseFiscalized(LoyProvidersRegistryImpl.java:362)
  268.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.purchaseFiscalized(LoyalServiceImpl.java:1547)
  269.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.purchaseFiscalized(LoyalBridgeServiceImpl.java:189)
  270.     at ru.crystals.pos.techprocess.ExternalProcessingsImpl.purchaseFiscalized(ExternalProcessingsImpl.java:212)
  271.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1793)
  272.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  273.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeReturnCheck(TechProcessShiftProxy.java:718)
  274.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:698)
  275.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  276.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  277.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  278.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  279.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  280.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  281.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  282.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  283.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  284.     at ru.crystals.pos.visualization.payments.cash.CashPaymentContainer.enter(CashPaymentContainer.java:94)
  285.     at ru.crystals.pos.visualization.components.CompositeContainer.enter(CompositeContainer.java:97)
  286.     at ru.crystals.pos.visualization.check.CheckContainer.enter(CheckContainer.java:1920)
  287.     at ru.crystals.pos.visualization.components.MainWindow.enter(MainWindow.java:1086)
  288.     at ru.crystals.pos.visualization.Factory.eventControlKey(Factory.java:536)
  289.     at ru.crystals.pos.techprocess.TechProcessImpl.eventControlKey(TechProcessImpl.java:4355)
  290.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:167)
  291.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  292.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  293.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  294.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  295.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  296.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  297.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  298.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  299.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  300.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  301.     at java.lang.Thread.run(Thread.java:745)
  302. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 203140ms.
  303.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  304.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  305.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  306.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  307.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  308.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  309.     ... 41 more
  310. 08.08 20:50:57.040 TRACE [SCService] Entering commitDiscounts (LoyTransactionEntity, PurchaseEntity). The arguments are loy-tx [shop: 1749, cash: 61, inn: 7802781104, shift: 18, purchase-number: (NULL), discount-value: 0, discount-positions: [discount-position [position-order: 1, discount-amount: 0, adv-action: adv-action [guid: -1673510823, action-type: DEFAULT, apply-mode: UNCONDITIONAL]], discount-position [position-order: 2, discount-amount: 0, adv-action: adv-action [guid: -1673510823, action-type: DEFAULT, apply-mode: UNCONDITIONAL]], discount-position [position-order: 3, discount-amount: 0, adv-action: adv-action [guid: -1673510823, action-type: DEFAULT, apply-mode: UNCONDITIONAL]]]], PurchaseEntity [id=24340, number=37, dateCreate=2019-08-08 20:46:36.702, dateCommit=Thu Aug 08 20:46:48 MSK 2019, fiscalDocNum=845;1585, sentToServerStatus=NO_SENT]
  311. 08.08 20:51:04.501 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  312. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  313.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  314.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  315.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  316.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  317.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  318.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  319.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  320.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  321.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  322.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  323.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  324.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  325.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  326.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  327.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  328.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  329.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  330.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  331.     at java.lang.Thread.run(Thread.java:745)
  332. 08.08 20:51:06.601 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  333. 08.08 20:51:06.823 ERROR [MLServiceImpl] Could not send pending operation (id: 168565; date: 2019-08-08 17:23:57.926)
  334. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  335.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  336.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  337.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  338.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  339.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  340.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  341.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  342.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  343.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  344.     at java.lang.Thread.run(Thread.java:745)
  345. 08.08 20:51:06.824 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  346.     Id: MQ==
  347.     Date: 2019-08-08 17:22:55.499
  348. 08.08 20:51:06.824 TRACE [MLServiceImpl] entering getServices()
  349. 08.08 20:51:06.824 TRACE [MLServiceImpl] getting services (IN MEMORY)
  350. 08.08 20:51:06.824 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  351. 08.08 20:51:06.824 TRACE [MLServiceImpl] Going to send DissociatingCard:
  352. 08.08 20:51:06.825 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  353. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  354.     <request>
  355.         <ClientTransactionId>1</ClientTransactionId>
  356.         <Organization>Victoria</Organization>
  357.         <BusinessUnit>1749</BusinessUnit>
  358.         <POS>61</POS>
  359.         <CardNumber>99990002</CardNumber>
  360.         <DateTime>2019-08-08T20:51:06.824+03:00</DateTime>
  361.     </request>
  362. </DissociatingCard>
  363.  
  364. 08.08 20:51:06.974 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  365. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  366.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  367.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  368.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  369.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  370.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  371.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  372.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  373.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  374.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  375.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  376.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  377.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  378.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  379.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  380.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  381.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  382.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  383.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  384.     at java.lang.Thread.run(Thread.java:745)
  385. 08.08 20:51:06.975 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  386. 08.08 20:51:06.979 ERROR [MLServiceImpl] Could not send pending operation (id: 168562; date: 2019-08-08 17:22:55.499)
  387. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  388.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  389.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  390.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  391.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  392.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  393.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  394.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  395.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  396.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  397.     at java.lang.Thread.run(Thread.java:745)
  398. 08.08 20:51:06.980 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  399.     Id: MQ==
  400.     Date: 2019-08-08 17:23:06.162
  401. 08.08 20:51:06.980 TRACE [MLServiceImpl] entering getServices()
  402. 08.08 20:51:06.980 TRACE [MLServiceImpl] getting services (IN MEMORY)
  403. 08.08 20:51:06.980 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  404. 08.08 20:51:06.980 TRACE [MLServiceImpl] Going to send DissociatingCard:
  405. 08.08 20:51:06.980 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  406. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  407.     <request>
  408.         <ClientTransactionId>1</ClientTransactionId>
  409.         <Organization>Victoria</Organization>
  410.         <BusinessUnit>1749</BusinessUnit>
  411.         <POS>61</POS>
  412.         <CardNumber>99990002</CardNumber>
  413.         <DateTime>2019-08-08T20:51:06.980+03:00</DateTime>
  414.     </request>
  415. </DissociatingCard>
  416.  
  417. 08.08 20:51:09.149 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  418. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  419.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  420.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  421.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  422.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  423.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  424.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  425.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  426.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  427.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  428.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  429.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  430.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  431.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  432.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  433.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  434.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  435.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  436.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  437.     at java.lang.Thread.run(Thread.java:745)
  438. 08.08 20:51:09.150 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  439. 08.08 20:51:09.170 ERROR [MLServiceImpl] Could not send pending operation (id: 168563; date: 2019-08-08 17:23:06.162)
  440. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  441.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  442.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  443.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  444.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  445.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  446.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  447.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  448.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  449.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  450.     at java.lang.Thread.run(Thread.java:745)
  451. 08.08 20:51:09.170 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  452.     Id: MQ==
  453.     Date: 2019-08-08 17:23:22.847
  454. 08.08 20:51:09.170 TRACE [MLServiceImpl] entering getServices()
  455. 08.08 20:51:09.170 TRACE [MLServiceImpl] getting services (IN MEMORY)
  456. 08.08 20:51:09.170 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  457. 08.08 20:51:09.170 TRACE [MLServiceImpl] Going to send DissociatingCard:
  458. 08.08 20:51:09.171 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  459. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  460.     <request>
  461.         <ClientTransactionId>1</ClientTransactionId>
  462.         <Organization>Victoria</Organization>
  463.         <BusinessUnit>1749</BusinessUnit>
  464.         <POS>61</POS>
  465.         <CardNumber>99990005</CardNumber>
  466.         <DateTime>2019-08-08T20:51:09.170+03:00</DateTime>
  467.     </request>
  468. </DissociatingCard>
  469.  
  470. 08.08 20:51:09.295 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  471. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  472.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  473.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  474.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  475.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  476.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  477.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  478.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  479.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  480.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  481.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  482.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  483.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  484.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  485.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  486.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  487.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  488.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  489.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  490.     at java.lang.Thread.run(Thread.java:745)
  491. 08.08 20:51:09.296 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  492. 08.08 20:51:09.299 ERROR [MLServiceImpl] Could not send pending operation (id: 168564; date: 2019-08-08 17:23:22.847)
  493. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  494.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  495.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  496.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  497.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  498.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  499.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  500.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  501.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  502.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  503.     at java.lang.Thread.run(Thread.java:745)
  504. 08.08 20:51:10.729 DEBUG [TechProcessImpl] Server online mode
  505. 08.08 20:51:11.500 INFO  [TransferManager] OD found 0 documents to register
  506. 08.08 20:51:11.560 ERROR [CommonLogger] Error on addPayment:
  507. org.hibernate.TransactionException: Transaction not successfully started
  508.     at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:202)
  509.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3978)
  510.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  511.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  512.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  513.     at ru.crystals.pos.visualization.payments.cash.CashPaymentContainer.enter(CashPaymentContainer.java:94)
  514.     at ru.crystals.pos.visualization.components.CompositeContainer.enter(CompositeContainer.java:97)
  515.     at ru.crystals.pos.visualization.check.CheckContainer.enter(CheckContainer.java:1920)
  516.     at ru.crystals.pos.visualization.components.MainWindow.enter(MainWindow.java:1086)
  517.     at ru.crystals.pos.visualization.Factory.eventControlKey(Factory.java:536)
  518.     at ru.crystals.pos.techprocess.TechProcessImpl.eventControlKey(TechProcessImpl.java:4355)
  519.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:167)
  520.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  521.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  522.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  523.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  524.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  525.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  526.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  527.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  528.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  529.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  530.     at java.lang.Thread.run(Thread.java:745)
  531. 08.08 20:51:14.468 INFO  [DocumentSender] OD found 0 transactions to register
  532. 08.08 20:51:15.591 INFO  [DocumentSender] response message = Created
  533. 08.08 20:51:15.592 INFO  [TransferManager] Send document status : 24309 > WAIT_ACKNOWLEDGEMENT            file name : 61/Document_20190808205114_953_1749_61.ser
  534. 08.08 20:51:16.544 INFO  [CheckService] SetSentToServerStatus : 24309 > WAIT_ACKNOWLEDGEMENT file name : 61/Document_20190808205114_953_1749_61.ser
  535. 08.08 20:51:16.615 INFO  [DocumentSender] document 61/Document_20190808205114_953_1749_61.ser has been registered
  536. 08.08 20:51:16.615 INFO  [TransferManager] Send document status : 24309 > SENT            file name : 61/Document_20190808205114_953_1749_61.ser
  537. 08.08 20:51:16.620 INFO  [CheckService] SetSentToServerStatus : 24309 > SENT file name : 61/Document_20190808205114_953_1749_61.ser
  538. 08.08 20:51:18.554 INFO  [FiscalPrinter] resetException()
  539. 08.08 20:51:26.196 ERROR [TransactionHandler]
  540. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 33867ms.
  541.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  542.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  543.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  544.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  545.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  546.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  547.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  548.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  549.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  550.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  551.     at java.lang.Thread.run(Thread.java:745)
  552. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 33867ms.
  553.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  554.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  555.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  556.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  557.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  558.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  559.     ... 10 more
  560. 08.08 20:51:26.193 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
  561. 08.08 20:51:26.193 INFO  [DocumentSender] OD found 0 payment transactions
  562. 08.08 20:51:26.215 INFO  [CashConfigurationUpdateChecker] Received patches list: []
  563. 08.08 20:51:26.229 INFO  [DocumentSender] ping = true
  564. 08.08 20:51:26.229 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
  565. 08.08 20:51:26.230 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  566. 08.08 20:51:26.197 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  567. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 33867ms.
  568.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  569.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  570.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  571.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  572.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  573.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  574.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  575.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  576.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  577.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  578.     at java.lang.Thread.run(Thread.java:745)
  579. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 33867ms.
  580.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  581.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  582.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  583.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  584.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  585.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  586.     ... 10 more
  587. 08.08 20:51:26.281 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = set-loy-provider
  588. 08.08 20:51:26.917 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  589. 08.08 20:51:27.027 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  590. 08.08 20:51:32.327 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:51:32 will be deleted.
  591. 08.08 20:51:32.346 INFO  [CommonLogger] Cleaning done.
  592. 08.08 20:51:41.068 DEBUG [TechProcessImpl] Server online mode
  593. 08.08 20:51:41.715 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  594. 08.08 20:51:46.884 ERROR [TransactionHandler]
  595. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30264ms.
  596.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  597.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  598.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  599.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  600.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  601.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  602.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  603.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  604.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  605.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  606.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  607.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  608.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  609.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  610.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  611.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  612.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  613.     at java.lang.Thread.run(Thread.java:745)
  614. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30264ms.
  615.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  616.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  617.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  618.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  619.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  620.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  621.     ... 17 more
  622. 08.08 20:51:45.639 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  623. 08.08 20:51:48.359 ERROR [JDBCMapperImpl] Cannot rollback transaction
  624. java.lang.NullPointerException
  625.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  626.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  627.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  628.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  629.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  630.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  631.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  632.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  633.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  634.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  635.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  636.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  637.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  638.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  639.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  640.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  641.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  642.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  643.     at java.lang.Thread.run(Thread.java:745)
  644. 08.08 20:51:48.360 ERROR [TransferManager] Error during sending transactions, java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30264ms.
  645. 08.08 20:51:48.382 INFO  [HttpClient] Set url - http://172.29.17.49:8090/SetXRMI/TransportServlet
  646. 08.08 20:51:56.465 ERROR [TransactionHandler]
  647. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30184ms.
  648.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  649.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  650.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  651.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  652.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  653.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  654.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  655.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  656.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  657.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  658.     at java.lang.Thread.run(Thread.java:745)
  659. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30184ms.
  660.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  661.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  662.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  663.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  664.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  665.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  666.     ... 10 more
  667. 08.08 20:51:56.466 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  668. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30184ms.
  669.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  670.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  671.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  672.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  673.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  674.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  675.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  676.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  677.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  678.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  679.     at java.lang.Thread.run(Thread.java:745)
  680. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30184ms.
  681.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  682.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  683.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  684.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  685.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  686.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  687.     ... 10 more
  688. 08.08 20:51:56.466 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = loymax
  689. 08.08 20:52:01.289 INFO  [FiscalPrinter] resetException()
  690. 08.08 20:52:01.435 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  691. 08.08 20:52:01.635 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  692. 08.08 20:52:01.836 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  693. 08.08 20:52:02.077 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  694. 08.08 20:52:02.292 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  695. 08.08 20:52:09.323 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  696. 08.08 20:52:09.327 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  697.     Id: MQ==
  698.     Date: 2019-08-08 17:23:57.926
  699. 08.08 20:52:09.327 TRACE [MLServiceImpl] entering getServices()
  700. 08.08 20:52:09.327 TRACE [MLServiceImpl] getting services (IN MEMORY)
  701. 08.08 20:52:09.327 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  702. 08.08 20:52:09.327 TRACE [MLServiceImpl] Going to send DissociatingCard:
  703. 08.08 20:52:09.328 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  704. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  705.     <request>
  706.         <ClientTransactionId>1</ClientTransactionId>
  707.         <Organization>Victoria</Organization>
  708.         <BusinessUnit>1749</BusinessUnit>
  709.         <POS>61</POS>
  710.         <CardNumber>99990002</CardNumber>
  711.         <DateTime>2019-08-08T20:52:09.327+03:00</DateTime>
  712.     </request>
  713. </DissociatingCard>
  714.  
  715. 08.08 20:52:09.362 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  716. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  717.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  718.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  719.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  720.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  721.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  722.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  723.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  724.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  725.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  726.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  727.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  728.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  729.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  730.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  731.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  732.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  733.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  734.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  735.     at java.lang.Thread.run(Thread.java:745)
  736. 08.08 20:52:09.399 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  737. 08.08 20:52:09.412 ERROR [MLServiceImpl] Could not send pending operation (id: 168565; date: 2019-08-08 17:23:57.926)
  738. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  739.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  740.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  741.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  742.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  743.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  744.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  745.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  746.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  747.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  748.     at java.lang.Thread.run(Thread.java:745)
  749. 08.08 20:52:09.413 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  750.     Id: MQ==
  751.     Date: 2019-08-08 17:22:55.499
  752. 08.08 20:52:09.413 TRACE [MLServiceImpl] entering getServices()
  753. 08.08 20:52:09.413 TRACE [MLServiceImpl] getting services (IN MEMORY)
  754. 08.08 20:52:09.413 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  755. 08.08 20:52:09.413 TRACE [MLServiceImpl] Going to send DissociatingCard:
  756. 08.08 20:52:09.413 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  757. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  758.     <request>
  759.         <ClientTransactionId>1</ClientTransactionId>
  760.         <Organization>Victoria</Organization>
  761.         <BusinessUnit>1749</BusinessUnit>
  762.         <POS>61</POS>
  763.         <CardNumber>99990002</CardNumber>
  764.         <DateTime>2019-08-08T20:52:09.413+03:00</DateTime>
  765.     </request>
  766. </DissociatingCard>
  767.  
  768. 08.08 20:52:09.454 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  769. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  770.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  771.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  772.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  773.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  774.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  775.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  776.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  777.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  778.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  779.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  780.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  781.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  782.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  783.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  784.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  785.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  786.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  787.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  788.     at java.lang.Thread.run(Thread.java:745)
  789. 08.08 20:52:09.455 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  790. 08.08 20:52:09.460 ERROR [MLServiceImpl] Could not send pending operation (id: 168562; date: 2019-08-08 17:22:55.499)
  791. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  792.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  793.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  794.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  795.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  796.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  797.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  798.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  799.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  800.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  801.     at java.lang.Thread.run(Thread.java:745)
  802. 08.08 20:52:09.460 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  803.     Id: MQ==
  804.     Date: 2019-08-08 17:23:06.162
  805. 08.08 20:52:09.460 TRACE [MLServiceImpl] entering getServices()
  806. 08.08 20:52:09.460 TRACE [MLServiceImpl] getting services (IN MEMORY)
  807. 08.08 20:52:09.461 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  808. 08.08 20:52:09.461 TRACE [MLServiceImpl] Going to send DissociatingCard:
  809. 08.08 20:52:09.461 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  810. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  811.     <request>
  812.         <ClientTransactionId>1</ClientTransactionId>
  813.         <Organization>Victoria</Organization>
  814.         <BusinessUnit>1749</BusinessUnit>
  815.         <POS>61</POS>
  816.         <CardNumber>99990002</CardNumber>
  817.         <DateTime>2019-08-08T20:52:09.461+03:00</DateTime>
  818.     </request>
  819. </DissociatingCard>
  820.  
  821. 08.08 20:52:09.549 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  822. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  823.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  824.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  825.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  826.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  827.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  828.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  829.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  830.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  831.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  832.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  833.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  834.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  835.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  836.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  837.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  838.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  839.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  840.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  841.     at java.lang.Thread.run(Thread.java:745)
  842. 08.08 20:52:09.551 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  843. 08.08 20:52:09.553 ERROR [MLServiceImpl] Could not send pending operation (id: 168563; date: 2019-08-08 17:23:06.162)
  844. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  845.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  846.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  847.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  848.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  849.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  850.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  851.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  852.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  853.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  854.     at java.lang.Thread.run(Thread.java:745)
  855. 08.08 20:52:09.561 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  856.     Id: MQ==
  857.     Date: 2019-08-08 17:23:22.847
  858. 08.08 20:52:09.561 TRACE [MLServiceImpl] entering getServices()
  859. 08.08 20:52:09.561 TRACE [MLServiceImpl] getting services (IN MEMORY)
  860. 08.08 20:52:09.561 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  861. 08.08 20:52:09.561 TRACE [MLServiceImpl] Going to send DissociatingCard:
  862. 08.08 20:52:09.562 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  863. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  864.     <request>
  865.         <ClientTransactionId>1</ClientTransactionId>
  866.         <Organization>Victoria</Organization>
  867.         <BusinessUnit>1749</BusinessUnit>
  868.         <POS>61</POS>
  869.         <CardNumber>99990005</CardNumber>
  870.         <DateTime>2019-08-08T20:52:09.561+03:00</DateTime>
  871.     </request>
  872. </DissociatingCard>
  873.  
  874. 08.08 20:52:09.624 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  875. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  876.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  877.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  878.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  879.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  880.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  881.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  882.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  883.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  884.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  885.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  886.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  887.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  888.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  889.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  890.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  891.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  892.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  893.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  894.     at java.lang.Thread.run(Thread.java:745)
  895. 08.08 20:52:09.695 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  896. 08.08 20:52:09.701 ERROR [MLServiceImpl] Could not send pending operation (id: 168564; date: 2019-08-08 17:23:22.847)
  897. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  898.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  899.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  900.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  901.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  902.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  903.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  904.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  905.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  906.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  907.     at java.lang.Thread.run(Thread.java:745)
  908. 08.08 20:52:11.322 DEBUG [TechProcessImpl] Server online mode
  909. 08.08 20:52:13.817 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
  910. 08.08 20:52:13.820 INFO  [PendingOperationQueue] No pending card operations found.
  911. 08.08 20:52:16.237 INFO  [DocumentSender] ping = true
  912. 08.08 20:52:18.960 INFO  [FiscalPrinter] resetException()
  913. 08.08 20:52:19.000 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  914. 08.08 20:52:19.201 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  915. 08.08 20:52:19.401 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  916. 08.08 20:52:19.618 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  917. 08.08 20:52:19.819 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  918. 08.08 20:52:26.230 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
  919. 08.08 20:52:26.237 INFO  [CashConfigurationUpdateChecker] Received patches list: []
  920. 08.08 20:52:26.242 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
  921. 08.08 20:52:26.242 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  922. 08.08 20:52:26.467 ERROR [TransactionHandler]
  923. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30000ms.
  924.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  925.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  926.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  927.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  928.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  929.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  930.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  931.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  932.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  933.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  934.     at java.lang.Thread.run(Thread.java:745)
  935. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30000ms.
  936.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  937.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  938.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  939.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  940.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  941.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  942.     ... 10 more
  943. 08.08 20:52:26.467 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  944. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30000ms.
  945.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  946.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  947.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  948.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  949.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  950.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  951.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  952.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  953.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  954.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  955.     at java.lang.Thread.run(Thread.java:745)
  956. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30000ms.
  957.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  958.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  959.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  960.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  961.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  962.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  963.     ... 10 more
  964. 08.08 20:52:26.467 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = sm
  965. 08.08 20:52:26.584 INFO  [TransferManager] OD found 0 documents to register
  966. 08.08 20:52:26.602 INFO  [DocumentSender] OD found 0 transactions to register
  967. 08.08 20:52:26.616 INFO  [DocumentSender] response message = Created
  968. 08.08 20:52:26.619 INFO  [TransferManager] Send document status : 24340 > WAIT_ACKNOWLEDGEMENT            file name : 61/Document_20190808205226_612_1749_61.ser
  969. 08.08 20:52:26.629 INFO  [CheckService] SetSentToServerStatus : 24340 > WAIT_ACKNOWLEDGEMENT file name : 61/Document_20190808205226_612_1749_61.ser
  970. 08.08 20:52:26.635 INFO  [DocumentSender] document 61/Document_20190808205226_612_1749_61.ser has been registered
  971. 08.08 20:52:26.635 INFO  [TransferManager] Send document status : 24340 > SENT            file name : 61/Document_20190808205226_612_1749_61.ser
  972. 08.08 20:52:26.643 INFO  [CheckService] SetSentToServerStatus : 24340 > SENT file name : 61/Document_20190808205226_612_1749_61.ser
  973. 08.08 20:52:26.972 INFO  [DocumentSender] OD found 0 payment transactions
  974. 08.08 20:52:31.250 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:52:31 will be deleted.
  975. 08.08 20:52:31.255 INFO  [CommonLogger] Cleaning done.
  976. 08.08 20:52:35.426 INFO  [FiscalPrinter] resetException()
  977. 08.08 20:52:35.465 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  978. 08.08 20:52:35.667 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  979. 08.08 20:52:35.867 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  980. 08.08 20:52:36.083 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  981. 08.08 20:52:36.286 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  982. 08.08 20:52:41.329 DEBUG [TechProcessImpl] Server online mode
  983. 08.08 20:52:52.357 INFO  [FiscalPrinter] resetException()
  984. 08.08 20:52:52.397 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  985. 08.08 20:52:52.598 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  986. 08.08 20:52:52.798 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  987. 08.08 20:52:53.011 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  988. 08.08 20:52:53.213 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  989. 08.08 20:52:56.475 ERROR [TransactionHandler]
  990. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  991.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  992.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  993.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  994.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  995.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  996.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  997.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  998.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  999.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1000.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1001.     at java.lang.Thread.run(Thread.java:745)
  1002. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1003.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1004.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1005.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1006.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1007.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1008.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1009.     ... 10 more
  1010. 08.08 20:52:56.476 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  1011. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1012.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1013.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1014.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1015.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1016.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1017.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1018.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1019.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1020.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1021.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1022.     at java.lang.Thread.run(Thread.java:745)
  1023. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1024.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1025.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1026.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1027.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1028.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1029.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1030.     ... 10 more
  1031. 08.08 20:52:56.476 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = aeroflotBonusesCFT
  1032. 08.08 20:53:06.246 INFO  [DocumentSender] ping = true
  1033. 08.08 20:53:08.820 INFO  [FiscalPrinter] resetException()
  1034. 08.08 20:53:08.863 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1035. 08.08 20:53:09.064 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1036. 08.08 20:53:09.264 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1037. 08.08 20:53:09.473 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1038. 08.08 20:53:09.675 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1039. 08.08 20:53:09.705 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  1040. 08.08 20:53:09.705 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1041.     Id: MQ==
  1042.     Date: 2019-08-08 17:23:57.926
  1043. 08.08 20:53:09.705 TRACE [MLServiceImpl] entering getServices()
  1044. 08.08 20:53:09.705 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1045. 08.08 20:53:09.705 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1046. 08.08 20:53:09.705 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1047. 08.08 20:53:09.706 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1048. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1049.     <request>
  1050.         <ClientTransactionId>1</ClientTransactionId>
  1051.         <Organization>Victoria</Organization>
  1052.         <BusinessUnit>1749</BusinessUnit>
  1053.         <POS>61</POS>
  1054.         <CardNumber>99990002</CardNumber>
  1055.         <DateTime>2019-08-08T20:53:09.705+03:00</DateTime>
  1056.     </request>
  1057. </DissociatingCard>
  1058.  
  1059. 08.08 20:53:09.797 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1060. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1061.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1062.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1063.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1064.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1065.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1066.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1067.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1068.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1069.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1070.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1071.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1072.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1073.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1074.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1075.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1076.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1077.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1078.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1079.     at java.lang.Thread.run(Thread.java:745)
  1080. 08.08 20:53:09.813 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1081. 08.08 20:53:09.815 ERROR [MLServiceImpl] Could not send pending operation (id: 168565; date: 2019-08-08 17:23:57.926)
  1082. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1083.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1084.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1085.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1086.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1087.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1088.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1089.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1090.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1091.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1092.     at java.lang.Thread.run(Thread.java:745)
  1093. 08.08 20:53:09.815 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1094.     Id: MQ==
  1095.     Date: 2019-08-08 17:22:55.499
  1096. 08.08 20:53:09.815 TRACE [MLServiceImpl] entering getServices()
  1097. 08.08 20:53:09.815 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1098. 08.08 20:53:09.816 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1099. 08.08 20:53:09.816 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1100. 08.08 20:53:09.816 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1101. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1102.     <request>
  1103.         <ClientTransactionId>1</ClientTransactionId>
  1104.         <Organization>Victoria</Organization>
  1105.         <BusinessUnit>1749</BusinessUnit>
  1106.         <POS>61</POS>
  1107.         <CardNumber>99990002</CardNumber>
  1108.         <DateTime>2019-08-08T20:53:09.816+03:00</DateTime>
  1109.     </request>
  1110. </DissociatingCard>
  1111.  
  1112. 08.08 20:53:09.876 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1113. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1114.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1115.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1116.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1117.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1118.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1119.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1120.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1121.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1122.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1123.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1124.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1125.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1126.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1127.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1128.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1129.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1130.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1131.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1132.     at java.lang.Thread.run(Thread.java:745)
  1133. 08.08 20:53:09.878 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1134. 08.08 20:53:09.883 ERROR [MLServiceImpl] Could not send pending operation (id: 168562; date: 2019-08-08 17:22:55.499)
  1135. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1136.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1137.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1138.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1139.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1140.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1141.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1142.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1143.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1144.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1145.     at java.lang.Thread.run(Thread.java:745)
  1146. 08.08 20:53:09.883 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1147.     Id: MQ==
  1148.     Date: 2019-08-08 17:23:06.162
  1149. 08.08 20:53:09.883 TRACE [MLServiceImpl] entering getServices()
  1150. 08.08 20:53:09.883 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1151. 08.08 20:53:09.883 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1152. 08.08 20:53:09.883 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1153. 08.08 20:53:09.884 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1154. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1155.     <request>
  1156.         <ClientTransactionId>1</ClientTransactionId>
  1157.         <Organization>Victoria</Organization>
  1158.         <BusinessUnit>1749</BusinessUnit>
  1159.         <POS>61</POS>
  1160.         <CardNumber>99990002</CardNumber>
  1161.         <DateTime>2019-08-08T20:53:09.883+03:00</DateTime>
  1162.     </request>
  1163. </DissociatingCard>
  1164.  
  1165. 08.08 20:53:09.972 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1166. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1167.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1168.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1169.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1170.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1171.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1172.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1173.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1174.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1175.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1176.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1177.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1178.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1179.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1180.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1181.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1182.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1183.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1184.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1185.     at java.lang.Thread.run(Thread.java:745)
  1186. 08.08 20:53:09.974 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1187. 08.08 20:53:09.977 ERROR [MLServiceImpl] Could not send pending operation (id: 168563; date: 2019-08-08 17:23:06.162)
  1188. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1189.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1190.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1191.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1192.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1193.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1194.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1195.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1196.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1197.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1198.     at java.lang.Thread.run(Thread.java:745)
  1199. 08.08 20:53:09.977 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1200.     Id: MQ==
  1201.     Date: 2019-08-08 17:23:22.847
  1202. 08.08 20:53:09.977 TRACE [MLServiceImpl] entering getServices()
  1203. 08.08 20:53:09.977 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1204. 08.08 20:53:09.977 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1205. 08.08 20:53:09.977 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1206. 08.08 20:53:09.978 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1207. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1208.     <request>
  1209.         <ClientTransactionId>1</ClientTransactionId>
  1210.         <Organization>Victoria</Organization>
  1211.         <BusinessUnit>1749</BusinessUnit>
  1212.         <POS>61</POS>
  1213.         <CardNumber>99990005</CardNumber>
  1214.         <DateTime>2019-08-08T20:53:09.977+03:00</DateTime>
  1215.     </request>
  1216. </DissociatingCard>
  1217.  
  1218. 08.08 20:53:10.040 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1219. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1220.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1221.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1222.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1223.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1224.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1225.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1226.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1227.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1228.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1229.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1230.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1231.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1232.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1233.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1234.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1235.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1236.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1237.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1238.     at java.lang.Thread.run(Thread.java:745)
  1239. 08.08 20:53:10.040 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1240. 08.08 20:53:10.046 ERROR [MLServiceImpl] Could not send pending operation (id: 168564; date: 2019-08-08 17:23:22.847)
  1241. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1242.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1243.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1244.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1245.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1246.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1247.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1248.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1249.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1250.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1251.     at java.lang.Thread.run(Thread.java:745)
  1252. 08.08 20:53:11.331 DEBUG [TechProcessImpl] Server online mode
  1253. 08.08 20:53:18.478 ERROR [TransactionHandler]
  1254. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30005ms.
  1255.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1256.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1257.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  1258.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  1259.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  1260.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  1261.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  1262.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  1263.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  1264.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  1265.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  1266.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1267.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1268.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1269.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1270.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1271.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1272.     at java.lang.Thread.run(Thread.java:745)
  1273. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30005ms.
  1274.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1275.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1276.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1277.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1278.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1279.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1280.     ... 17 more
  1281. 08.08 20:53:18.479 ERROR [TransferManager] Error during sending transactions, java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30005ms.
  1282. 08.08 20:53:18.483 INFO  [HttpClient] Set url - http://172.29.17.49:8090/SetXRMI/TransportServlet
  1283. 08.08 20:53:25.947 INFO  [FiscalPrinter] resetException()
  1284. 08.08 20:53:25.991 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1285. 08.08 20:53:26.192 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1286. 08.08 20:53:26.242 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
  1287. 08.08 20:53:26.247 INFO  [CashConfigurationUpdateChecker] Received patches list: []
  1288. 08.08 20:53:26.250 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
  1289. 08.08 20:53:26.251 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  1290. 08.08 20:53:26.393 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1291. 08.08 20:53:26.483 ERROR [TransactionHandler]
  1292. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30006ms.
  1293.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1294.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1295.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1296.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1297.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1298.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1299.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1300.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1301.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1302.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1303.     at java.lang.Thread.run(Thread.java:745)
  1304. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30006ms.
  1305.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1306.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1307.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1308.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1309.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1310.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1311.     ... 10 more
  1312. 08.08 20:53:26.483 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  1313. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30006ms.
  1314.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1315.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1316.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1317.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1318.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1319.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1320.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1321.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1322.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1323.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1324.     at java.lang.Thread.run(Thread.java:745)
  1325. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30006ms.
  1326.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1327.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1328.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1329.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1330.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1331.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1332.     ... 10 more
  1333. 08.08 20:53:26.484 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = SetApiLoyaltyPlugin
  1334. 08.08 20:53:26.602 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1335. 08.08 20:53:26.803 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1336. 08.08 20:53:27.257 INFO  [TransferManager] OD found 0 documents to register
  1337. 08.08 20:53:27.274 INFO  [DocumentSender] OD found 0 transactions to register
  1338. 08.08 20:53:31.250 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:53:31 will be deleted.
  1339. 08.08 20:53:31.253 INFO  [CommonLogger] Cleaning done.
  1340. 08.08 20:53:41.331 DEBUG [TechProcessImpl] Server online mode
  1341. 08.08 20:53:42.348 INFO  [FiscalPrinter] resetException()
  1342. 08.08 20:53:42.390 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1343. 08.08 20:53:42.590 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1344. 08.08 20:53:42.791 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1345. 08.08 20:53:43.005 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1346. 08.08 20:53:43.207 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1347. 08.08 20:53:56.253 INFO  [DocumentSender] ping = true
  1348. 08.08 20:53:56.486 ERROR [TransactionHandler]
  1349. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30002ms.
  1350.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1351.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1352.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1353.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1354.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1355.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1356.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1357.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1358.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1359.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1360.     at java.lang.Thread.run(Thread.java:745)
  1361. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30002ms.
  1362.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1363.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1364.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1365.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1366.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1367.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1368.     ... 10 more
  1369. 08.08 20:53:56.487 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  1370. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30002ms.
  1371.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1372.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1373.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1374.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1375.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1376.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1377.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1378.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1379.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1380.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1381.     at java.lang.Thread.run(Thread.java:745)
  1382. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30002ms.
  1383.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1384.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1385.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1386.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1387.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1388.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1389.     ... 10 more
  1390. 08.08 20:53:56.487 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = kopilka
  1391. 08.08 20:53:59.421 INFO  [FiscalPrinter] resetException()
  1392. 08.08 20:53:59.459 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1393. 08.08 20:53:59.660 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1394. 08.08 20:53:59.861 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1395. 08.08 20:54:00.072 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1396. 08.08 20:54:00.274 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1397. 08.08 20:54:10.049 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  1398. 08.08 20:54:10.049 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1399.     Id: MQ==
  1400.     Date: 2019-08-08 17:23:57.926
  1401. 08.08 20:54:10.049 TRACE [MLServiceImpl] entering getServices()
  1402. 08.08 20:54:10.049 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1403. 08.08 20:54:10.049 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1404. 08.08 20:54:10.050 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1405. 08.08 20:54:10.050 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1406. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1407.     <request>
  1408.         <ClientTransactionId>1</ClientTransactionId>
  1409.         <Organization>Victoria</Organization>
  1410.         <BusinessUnit>1749</BusinessUnit>
  1411.         <POS>61</POS>
  1412.         <CardNumber>99990002</CardNumber>
  1413.         <DateTime>2019-08-08T20:54:10.049+03:00</DateTime>
  1414.     </request>
  1415. </DissociatingCard>
  1416.  
  1417. 08.08 20:54:10.064 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1418. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1419.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1420.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1421.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1422.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1423.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1424.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1425.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1426.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1427.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1428.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1429.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1430.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1431.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1432.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1433.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1434.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1435.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1436.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1437.     at java.lang.Thread.run(Thread.java:745)
  1438. 08.08 20:54:10.064 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1439. 08.08 20:54:10.091 ERROR [MLServiceImpl] Could not send pending operation (id: 168565; date: 2019-08-08 17:23:57.926)
  1440. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1441.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1442.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1443.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1444.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1445.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1446.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1447.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1448.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1449.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1450.     at java.lang.Thread.run(Thread.java:745)
  1451. 08.08 20:54:10.091 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1452.     Id: MQ==
  1453.     Date: 2019-08-08 17:22:55.499
  1454. 08.08 20:54:10.091 TRACE [MLServiceImpl] entering getServices()
  1455. 08.08 20:54:10.091 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1456. 08.08 20:54:10.091 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1457. 08.08 20:54:10.091 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1458. 08.08 20:54:10.092 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1459. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1460.     <request>
  1461.         <ClientTransactionId>1</ClientTransactionId>
  1462.         <Organization>Victoria</Organization>
  1463.         <BusinessUnit>1749</BusinessUnit>
  1464.         <POS>61</POS>
  1465.         <CardNumber>99990002</CardNumber>
  1466.         <DateTime>2019-08-08T20:54:10.091+03:00</DateTime>
  1467.     </request>
  1468. </DissociatingCard>
  1469.  
  1470. 08.08 20:54:10.159 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1471. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1472.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1473.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1474.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1475.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1476.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1477.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1478.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1479.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1480.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1481.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1482.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1483.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1484.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1485.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1486.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1487.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1488.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1489.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1490.     at java.lang.Thread.run(Thread.java:745)
  1491. 08.08 20:54:10.162 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1492. 08.08 20:54:10.168 ERROR [MLServiceImpl] Could not send pending operation (id: 168562; date: 2019-08-08 17:22:55.499)
  1493. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1494.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1495.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1496.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1497.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1498.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1499.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1500.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1501.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1502.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1503.     at java.lang.Thread.run(Thread.java:745)
  1504. 08.08 20:54:10.168 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1505.     Id: MQ==
  1506.     Date: 2019-08-08 17:23:06.162
  1507. 08.08 20:54:10.169 TRACE [MLServiceImpl] entering getServices()
  1508. 08.08 20:54:10.169 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1509. 08.08 20:54:10.169 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1510. 08.08 20:54:10.169 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1511. 08.08 20:54:10.169 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1512. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1513.     <request>
  1514.         <ClientTransactionId>1</ClientTransactionId>
  1515.         <Organization>Victoria</Organization>
  1516.         <BusinessUnit>1749</BusinessUnit>
  1517.         <POS>61</POS>
  1518.         <CardNumber>99990002</CardNumber>
  1519.         <DateTime>2019-08-08T20:54:10.169+03:00</DateTime>
  1520.     </request>
  1521. </DissociatingCard>
  1522.  
  1523. 08.08 20:54:10.236 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1524. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1525.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1526.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1527.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1528.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1529.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1530.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1531.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1532.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1533.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1534.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1535.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1536.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1537.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1538.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1539.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1540.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1541.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1542.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1543.     at java.lang.Thread.run(Thread.java:745)
  1544. 08.08 20:54:10.237 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1545. 08.08 20:54:10.283 ERROR [MLServiceImpl] Could not send pending operation (id: 168563; date: 2019-08-08 17:23:06.162)
  1546. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1547.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1548.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1549.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1550.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1551.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1552.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1553.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1554.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1555.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1556.     at java.lang.Thread.run(Thread.java:745)
  1557. 08.08 20:54:10.284 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1558.     Id: MQ==
  1559.     Date: 2019-08-08 17:23:22.847
  1560. 08.08 20:54:10.284 TRACE [MLServiceImpl] entering getServices()
  1561. 08.08 20:54:10.284 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1562. 08.08 20:54:10.284 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1563. 08.08 20:54:10.284 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1564. 08.08 20:54:10.284 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1565. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1566.     <request>
  1567.         <ClientTransactionId>1</ClientTransactionId>
  1568.         <Organization>Victoria</Organization>
  1569.         <BusinessUnit>1749</BusinessUnit>
  1570.         <POS>61</POS>
  1571.         <CardNumber>99990005</CardNumber>
  1572.         <DateTime>2019-08-08T20:54:10.284+03:00</DateTime>
  1573.     </request>
  1574. </DissociatingCard>
  1575.  
  1576. 08.08 20:54:10.294 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1577. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1578.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1579.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1580.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1581.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1582.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1583.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1584.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1585.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1586.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1587.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1588.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1589.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1590.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1591.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1592.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1593.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1594.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1595.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1596.     at java.lang.Thread.run(Thread.java:745)
  1597. 08.08 20:54:10.294 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1598. 08.08 20:54:10.300 ERROR [MLServiceImpl] Could not send pending operation (id: 168564; date: 2019-08-08 17:23:22.847)
  1599. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1600.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1601.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1602.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1603.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1604.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1605.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1606.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1607.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1608.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1609.     at java.lang.Thread.run(Thread.java:745)
  1610. 08.08 20:54:11.332 DEBUG [TechProcessImpl] Server online mode
  1611. 08.08 20:54:13.820 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
  1612. 08.08 20:54:13.823 INFO  [PendingOperationQueue] No pending card operations found.
  1613. 08.08 20:54:15.905 INFO  [FiscalPrinter] resetException()
  1614. 08.08 20:54:15.962 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1615. 08.08 20:54:16.163 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1616. 08.08 20:54:16.364 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1617. 08.08 20:54:16.575 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1618. 08.08 20:54:16.778 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1619. 08.08 20:54:26.251 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
  1620. 08.08 20:54:26.255 INFO  [CashConfigurationUpdateChecker] Received patches list: []
  1621. 08.08 20:54:26.258 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
  1622. 08.08 20:54:26.259 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  1623. 08.08 20:54:26.495 ERROR [TransactionHandler]
  1624. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1625.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1626.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1627.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1628.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1629.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1630.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1631.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1632.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1633.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1634.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1635.     at java.lang.Thread.run(Thread.java:745)
  1636. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1637.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1638.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1639.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1640.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1641.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1642.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1643.     ... 10 more
  1644. 08.08 20:54:26.495 ERROR [LoyProvidersRegistryImpl] failed to send stale feedbacks... this time
  1645. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1646.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1647.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1648.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndTime(Unknown Source)
  1649.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.lambda$init$0(LoyProvidersRegistryImpl.java:249)
  1650.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1651.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1652.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1653.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1654.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1655.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1656.     at java.lang.Thread.run(Thread.java:745)
  1657. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30007ms.
  1658.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1659.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1660.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1661.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1662.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1663.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1664.     ... 10 more
  1665. 08.08 20:54:28.310 INFO  [TransferManager] OD found 0 documents to register
  1666. 08.08 20:54:28.783 INFO  [DocumentSender] OD found 0 transactions to register
  1667. 08.08 20:54:31.250 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 20:54:31 will be deleted.
  1668. 08.08 20:54:31.319 INFO  [CommonLogger] Cleaning done.
  1669. 08.08 20:54:33.256 INFO  [FiscalPrinter] resetException()
  1670. 08.08 20:54:33.339 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1671. 08.08 20:54:33.540 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1672. 08.08 20:54:33.740 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1673. 08.08 20:54:33.959 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1674. 08.08 20:54:34.160 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1675. 08.08 20:54:41.332 DEBUG [TechProcessImpl] Server online mode
  1676. 08.08 20:54:48.516 ERROR [TransactionHandler]
  1677. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30003ms.
  1678.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  1679.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  1680.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  1681.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  1682.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  1683.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  1684.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  1685.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  1686.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  1687.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  1688.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  1689.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1690.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1691.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1692.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1693.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1694.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1695.     at java.lang.Thread.run(Thread.java:745)
  1696. Caused by: java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30003ms.
  1697.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  1698.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  1699.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  1700.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  1701.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  1702.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  1703.     ... 17 more
  1704. 08.08 20:54:48.517 ERROR [JDBCMapperImpl] Cannot rollback transaction
  1705. java.lang.NullPointerException
  1706.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  1707.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  1708.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  1709.     at com.sun.proxy.$Proxy213.getFeedbackByProviderAndChequeId(Unknown Source)
  1710.     at ru.crystals.loyal.providers.AbstractLoyProvider.isHavingFeedbacks(AbstractLoyProvider.java:113)
  1711.     at ru.crystals.pos.loyal.loymax.LoymaxLoyProvider.isLoyTransactionComplete(LoymaxLoyProvider.java:228)
  1712.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.isLoyTransactionComplete(LoyProvidersRegistryImpl.java:390)
  1713.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.isLoyTransactionComplete(LoyalServiceImpl.java:1712)
  1714.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.isLoyTransactionComplete(LoyalBridgeServiceImpl.java:355)
  1715.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.sendLoyTransactions(TransferManager.java:242)
  1716.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$100(TransferManager.java:55)
  1717.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:105)
  1718.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1719.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1720.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1721.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1722.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1723.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1724.     at java.lang.Thread.run(Thread.java:745)
  1725. 08.08 20:54:48.517 ERROR [TransferManager] Error during sending transactions, java.sql.SQLTransientConnectionException: HikariPool-10 - Connection is not available, request timed out after 30003ms.
  1726. 08.08 20:54:48.518 INFO  [HttpClient] Set url - http://172.29.17.49:8090/SetXRMI/TransportServlet
  1727. 08.08 20:54:49.691 INFO  [FiscalPrinter] resetException()
  1728. 08.08 20:54:49.739 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1729. 08.08 20:54:49.940 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1730. 08.08 20:54:50.140 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1731. 08.08 20:54:50.357 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1732. 08.08 20:54:50.559 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1733. 08.08 20:55:06.355 INFO  [FiscalPrinter] resetException()
  1734. 08.08 20:55:06.398 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1735. 08.08 20:55:06.599 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1736. 08.08 20:55:06.801 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  1737. 08.08 20:55:07.020 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1738. 08.08 20:55:07.222 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  1739. 08.08 20:55:10.316 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  1740. 08.08 20:55:10.316 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1741.     Id: MQ==
  1742.     Date: 2019-08-08 17:23:57.926
  1743. 08.08 20:55:10.316 TRACE [MLServiceImpl] entering getServices()
  1744. 08.08 20:55:10.316 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1745. 08.08 20:55:10.316 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1746. 08.08 20:55:10.316 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1747. 08.08 20:55:10.317 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1748. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1749.     <request>
  1750.         <ClientTransactionId>1</ClientTransactionId>
  1751.         <Organization>Victoria</Organization>
  1752.         <BusinessUnit>1749</BusinessUnit>
  1753.         <POS>61</POS>
  1754.         <CardNumber>99990002</CardNumber>
  1755.         <DateTime>2019-08-08T20:55:10.316+03:00</DateTime>
  1756.     </request>
  1757. </DissociatingCard>
  1758.  
  1759. 08.08 20:55:10.363 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1760. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: ru.crystals.pos.ml.wsclient.DissociatingCardRequest cannot be cast to ru.crystals.pos.ml.wsclient.ProcessRequest$Request Please see the server log to find more detail regarding exact cause of the failure.
  1761.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1762.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1763.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1764.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1765.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1766.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1767.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1768.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1769.     at com.sun.proxy.$Proxy245.dissociatingCard(Unknown Source)
  1770.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  1771.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1772.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1773.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1774.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1775.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1776.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1777.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1778.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1779.     at java.lang.Thread.run(Thread.java:745)
  1780. 08.08 20:55:10.364 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1781. 08.08 20:55:10.368 ERROR [MLServiceImpl] Could not send pending operation (id: 168565; date: 2019-08-08 17:23:57.926)
  1782. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1783.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  1784.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  1785.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  1786.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1787.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1788.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1789.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1790.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1791.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1792.     at java.lang.Thread.run(Thread.java:745)
  1793. 08.08 20:55:10.369 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1794.     Id: MQ==
  1795.     Date: 2019-08-08 17:22:55.499
  1796. 08.08 20:55:10.369 TRACE [MLServiceImpl] entering getServices()
  1797. 08.08 20:55:10.369 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1798. 08.08 20:55:10.369 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1799. 08.08 20:55:10.369 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1800. 08.08 20:55:10.369 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1801. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1802.     <request>
  1803.         <ClientTransactionId>1</ClientTransactionId>
  1804.         <Organization>Victoria</Organization>
  1805.         <BusinessUnit>1749</BusinessUnit>
  1806.         <POS>61</POS>
  1807.         <CardNumber>99990002</CardNumber>
  1808.         <DateTime>2019-08-08T20:55:10.369+03:00</DateTime>
  1809.     </request>
  1810. </DissociatingCard>
Advertisement
Add Comment
Please, Sign In to add comment
Advertisement
Public Pastes
Advertisement
We use cookies for various purposes including analytics. By continuing to use Pastebin, you agree to our use of cookies as described in the Cookies Policy.  OK, I Understand
Not a member of Pastebin yet?
Sign Up, it unlocks many cool features!