API tools faq
paste
Advertisement
fedorm

fedorm

fedorm
Sep 17th, 2018
238
0
Never
Add comment
Not a member of Pastebin yet? Sign Up, it unlocks many cool features!
XML 136.08 KB | None | 0 0
raw download clone embed print report
  1. 17.09 04:05:10 INFO  [DocumentTemplate] =====logo=====
  2. 17.09 04:05:10 INFO  [DocumentTemplate] content: null
  3. 17.09 04:05:10 INFO  [DocumentTemplate] =====header=====
  4. 17.09 04:05:10 INFO  [DocumentTemplate]                    jr. name                   ||NORMAL
  5. 17.09 04:05:10 INFO  [DocumentTemplate]          199100, Spb, Savushkina, 112         ||NORMAL
  6. 17.09 04:05:10 INFO  [DocumentTemplate] ----------------------------------------      ||NORMAL
  7. 17.09 04:05:10 INFO  [DocumentTemplate] Смена:15                     ЭКЛЗ:a454701d-72f||NORMAL
  8. 17.09 04:05:10 INFO  [DocumentTemplate] Номер кассы:60                ИНН:  7802781104||NORMAL
  9. 17.09 04:05:10 INFO  [DocumentTemplate] Кассир:Кассиров Кассир Кассирович             ||NORMAL
  10. 17.09 04:05:10 INFO  [DocumentTemplate] ----------------------------------------      ||NORMAL
  11. 17.09 04:05:10 INFO  [DocumentTemplate] КАССОВЫЙ ЧЕК            196  17-09-2018  04:05||NORMAL
  12. 17.09 04:05:10 INFO  [DocumentTemplate] ----------------------------------------      ||NORMAL
  13. 17.09 04:05:10 INFO  [DocumentTemplate] =====position=====
  14. 17.09 04:05:10 INFO  [DocumentTemplate] Безалкогольный энергети  300.50*     1 =300.50||SMALL
  15. 17.09 04:05:10 INFO  [DocumentTemplate] =====fiscal=====
  16. 17.09 04:05:10 INFO  [DocumentTemplate] content: null
  17. 17.09 04:05:10 INFO  [DocumentTemplate] =====footer=====
  18. 17.09 04:05:10 INFO  [DocumentTemplate]  ******************************************** ||NORMAL
  19. 17.09 04:05:10 INFO  [DocumentTemplate] ЧЕК No.196 АННУЛИРОВАН||DOUBLEHEIGHT
  20. 17.09 04:05:10 INFO  [DocumentTemplate]  ******************************************** ||NORMAL
  21. 17.09 04:05:10 INFO  [DocumentTemplate] =====cut=====
  22. 17.09 04:05:10 INFO  [DocumentTemplate] content: null
  23. 17.09 04:05:11 INFO  [FiscalPrinter] getCountAnnul
  24. 17.09 04:05:11 INFO  [FiscalPrinter] CountAnnul = 13
  25. 17.09 04:05:11 INFO  [FiscalPrinter] getLastDocNum
  26. 17.09 04:05:12 INFO  [TransferManager] Nothing yet not processed on server to resend
  27. 17.09 04:05:12 INFO  [FilesChecker] Catalog goods transport event
  28. 17.09 04:05:13 INFO  [FilesChecker]    goods types for report count: 0
  29. 17.09 04:05:13 INFO  [FilesChecker]    catalog goods files to cash count: 0
  30. 17.09 04:05:13 INFO  [CheckServiceImpl] cancelCheck: PurchaseEntity [id=4544, number=196, dateCreate=Mon Sep 17 04:04:45 MSK 2018, dateCommit=Mon Sep 17 04:05:13 MSK 2018, fiscalDocNum=13;781, sentToServerStatus=NO_SENT]
  31. 17.09 04:05:14 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  32. 17.09 04:05:14 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  33.     Id: MQ==
  34.     Date: 2018-09-17 02:04:47.719
  35. 17.09 04:05:14 TRACE [MLServiceImpl] entering getServices()
  36. 17.09 04:05:14 TRACE [MLServiceImpl] getting services (IN MEMORY)
  37. 17.09 04:05:14 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  38. 17.09 04:05:14 TRACE [MLServiceImpl] Going to send DissociatingCard:
  39. 17.09 04:05:14 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  40. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  41.     <request>
  42.         <ClientTransactionId>1</ClientTransactionId>
  43.         <Organization>Victoria</Organization>
  44.         <BusinessUnit>1688</BusinessUnit>
  45.         <POS>60</POS>
  46.         <CardNumber>99990002</CardNumber>
  47.         <DateTime>2018-09-17T04:05:14.872+03:00</DateTime>
  48.     </request>
  49. </DissociatingCard>
  50.  
  51. 17.09 04:05:18 INFO  [TransferManager] ping = true
  52. 17.09 04:05:18 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  53. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  54.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  55.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  56.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  57.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  58.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  59.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  60.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  61.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  62.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  63.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  64.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  65.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  66.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  67.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  68.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  69.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  70.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  71.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  72.     at java.lang.Thread.run(Thread.java:745)
  73. 17.09 04:05:18 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  74. 17.09 04:05:18 ERROR [MLServiceImpl] Could not send pending operation (id: 111013; date: 2018-09-17 02:04:47.719)
  75. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  76.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  77.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  78.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  79.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  80.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  81.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  82.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  83.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  84.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  85.     at java.lang.Thread.run(Thread.java:745)
  86. 17.09 04:05:18 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  87.     Id: MQ==
  88.     Date: 2018-09-17 02:02:53.316
  89. 17.09 04:05:18 TRACE [MLServiceImpl] entering getServices()
  90. 17.09 04:05:18 TRACE [MLServiceImpl] getting services (IN MEMORY)
  91. 17.09 04:05:18 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  92. 17.09 04:05:18 TRACE [MLServiceImpl] Going to send DissociatingCard:
  93. 17.09 04:05:18 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  94. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  95.     <request>
  96.         <ClientTransactionId>1</ClientTransactionId>
  97.         <Organization>Victoria</Organization>
  98.         <BusinessUnit>1688</BusinessUnit>
  99.         <POS>60</POS>
  100.         <CardNumber>99990002</CardNumber>
  101.         <DateTime>2018-09-17T04:05:18.386+03:00</DateTime>
  102.     </request>
  103. </DissociatingCard>
  104.  
  105. 17.09 04:05:18 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  106. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  107.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  108.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  109.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  110.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  111.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  112.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  113.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  114.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  115.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  116.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  117.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  118.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  119.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  120.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  121.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  122.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  123.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  124.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  125.     at java.lang.Thread.run(Thread.java:745)
  126. 17.09 04:05:18 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  127. 17.09 04:05:18 ERROR [MLServiceImpl] Could not send pending operation (id: 111011; date: 2018-09-17 02:02:53.316)
  128. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  129.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  130.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  131.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  132.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  133.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  134.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  135.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  136.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  137.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  138.     at java.lang.Thread.run(Thread.java:745)
  139. 17.09 04:05:18 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  140.     Id: MQ==
  141.     Date: 2018-09-17 02:03:31.243
  142. 17.09 04:05:18 TRACE [MLServiceImpl] entering getServices()
  143. 17.09 04:05:18 TRACE [MLServiceImpl] getting services (IN MEMORY)
  144. 17.09 04:05:18 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  145. 17.09 04:05:18 TRACE [MLServiceImpl] Going to send DissociatingCard:
  146. 17.09 04:05:18 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  147. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  148.     <request>
  149.         <ClientTransactionId>1</ClientTransactionId>
  150.         <Organization>Victoria</Organization>
  151.         <BusinessUnit>1688</BusinessUnit>
  152.         <POS>60</POS>
  153.         <CardNumber>99990001</CardNumber>
  154.         <DateTime>2018-09-17T04:05:18.506+03:00</DateTime>
  155.     </request>
  156. </DissociatingCard>
  157.  
  158. 17.09 04:05:18 DEBUG [TechProcessImpl] Server online mode
  159. 17.09 04:05:18 TRACE [ExternalProcessingsImpl] seems that this cash is not aware of existence of CFT-backed loyality programms. So, there is no need to cancel CFT-backed bonuses charge-offs
  160. 17.09 04:05:18 TRACE [ExternalProcessingsImpl] seems that this cash is not aware of existence of CFT-backed loyality programms. So, there is no need to cancel CFT-backed bonuses charge-offs
  161. 17.09 04:05:18 TRACE [ExternalProcessingsImpl] Discounts cancelled: no implementation of PlastekServices.
  162. 17.09 04:05:18 TRACE [ExternalProcessingsImpl] entering discountCancelledToSet5(PurchaseEntity)
  163. 17.09 04:05:18 TRACE [ExternalProcessingsImpl] leaving discountCancelledToSet5(PurchaseEntity): the SET5 loy processing is disabled
  164. 17.09 04:05:19 WARN  [SetApiPluginLoyProvider] No loyal transaction entity found for purchase PurchaseEntity [id=4544, number=196, dateCreate=Mon Sep 17 04:04:45 MSK 2018, dateCommit=Mon Sep 17 04:05:13 MSK 2018, fiscalDocNum=13;781, sentToServerStatus=NO_SENT]
  165. 17.09 04:05:19 INFO  [TechProcessImpl] Select seller [null]
  166. 17.09 04:05:19 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":25,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":196,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":300.5,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:19.977","offline":false}]}
  167. 17.09 04:05:19 INFO  [SpeedLog] TechProcess cancelCheck time = 10348 ms
  168. 17.09 04:05:19 INFO  [WaitComponent] [WaitComponent] MainFrame enabled - true
  169. 17.09 04:05:19 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  170. 17.09 04:05:19 INFO  [TextCustomerDisplayPluginAbstract] **********************
  171. 17.09 04:05:19 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  172. 17.09 04:05:19 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  173. 17.09 04:05:19 INFO  [TextCustomerDisplayPluginAbstract] **********************
  174. 17.09 04:05:19 INFO  [TextCustomerDisplayPluginAbstract]
  175. 17.09 04:05:20 INFO  [TechProcessImpl] Select seller [null]
  176. 17.09 04:05:20 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  177. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  178.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  179.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  180.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  181.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  182.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  183.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  184.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  185.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  186.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  187.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  188.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  189.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  190.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  191.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  192.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  193.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  194.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  195.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  196.     at java.lang.Thread.run(Thread.java:745)
  197. 17.09 04:05:20 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  198. 17.09 04:05:20 ERROR [MLServiceImpl] Could not send pending operation (id: 111012; date: 2018-09-17 02:03:31.243)
  199. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  200.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  201.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  202.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  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. 17.09 04:05:20 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  211.     Id: MQ==
  212.     Date: 2018-09-17 02:02:17.864
  213. 17.09 04:05:20 TRACE [MLServiceImpl] entering getServices()
  214. 17.09 04:05:20 TRACE [MLServiceImpl] getting services (IN MEMORY)
  215. 17.09 04:05:20 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  216. 17.09 04:05:20 TRACE [MLServiceImpl] Going to send DissociatingCard:
  217. 17.09 04:05:20 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  218. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  219.     <request>
  220.         <ClientTransactionId>1</ClientTransactionId>
  221.         <Organization>Victoria</Organization>
  222.         <BusinessUnit>1688</BusinessUnit>
  223.         <POS>60</POS>
  224.         <CardNumber>99990002</CardNumber>
  225.         <DateTime>2018-09-17T04:05:20.022+03:00</DateTime>
  226.     </request>
  227. </DissociatingCard>
  228.  
  229. 17.09 04:05:20 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  230. 17.09 04:05:20 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  231. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  232.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  233.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  234.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  235.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  236.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  237.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  238.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  239.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  240.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  241.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  242.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  243.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  244.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  245.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  246.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  247.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  248.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  249.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  250.     at java.lang.Thread.run(Thread.java:745)
  251. 17.09 04:05:20 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  252. 17.09 04:05:20 ERROR [MLServiceImpl] Could not send pending operation (id: 111010; date: 2018-09-17 02:02:17.864)
  253. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  254.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  255.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  256.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  257.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  258.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  259.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  260.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  261.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  262.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  263.     at java.lang.Thread.run(Thread.java:745)
  264. 17.09 04:05:20 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  265. 17.09 04:05:20 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  266. 17.09 04:05:20 INFO  [TextCustomerDisplayPluginAbstract] **********************
  267. 17.09 04:05:20 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  268. 17.09 04:05:20 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  269. 17.09 04:05:20 INFO  [TextCustomerDisplayPluginAbstract] **********************
  270. 17.09 04:05:20 INFO  [TextCustomerDisplayPluginAbstract]
  271. 17.09 04:05:22 INFO  [TransferManager] OD found 1 documents
  272. 17.09 04:05:22 INFO  [TransferManager] response message = Created
  273. 17.09 04:05:22 INFO  [TransferManager] Send document status : 4544 > WAIT_ACKNOWLEDGEMENT            file name : 60/Document_20180917040522_657_1688_60.ser
  274. 17.09 04:05:22 INFO  [CheckServiceImpl] SetSentToServerStatus : 4544 > WAIT_ACKNOWLEDGEMENT file name : 60/Document_20180917040522_657_1688_60.ser
  275. 17.09 04:05:22 INFO  [FiscalPrinter] resetException()
  276. 17.09 04:05:22 INFO  [TransferManager] document 60/Document_20180917040522_657_1688_60.ser has been registreated
  277. 17.09 04:05:22 INFO  [TransferManager] Send document status : 4544 > SENT            file name : 60/Document_20180917040522_657_1688_60.ser
  278. 17.09 04:05:22 INFO  [CheckServiceImpl] SetSentToServerStatus : 4544 > SENT file name : 60/Document_20180917040522_657_1688_60.ser
  279. 17.09 04:05:22 INFO  [TransferManager] OD found 0 payment transactions
  280. 17.09 04:05:22 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=82, command=kbdMenu3]
  281. 17.09 04:05:22 ERROR [CFTBonusModel] getChargedOffBonusCards: either "receipt" [null], or "sponsorId" [BONUS_CFT] argument is NULL
  282. 17.09 04:05:22 ERROR [CFTBonusModel] getChargedOffBonusCards: either "receipt" [null], or "sponsorId" [BONUS_CFT] argument is NULL
  283. 17.09 04:05:23 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  284. 17.09 04:05:23 INFO  [CommonLogger] Menu command: Смена пользователя (class ru.crystals.pos.visualization.menu.commands.ChangeUserCommand)
  285. 17.09 04:05:23 INFO  [TechProcessImpl] userLogout
  286. 17.09 04:05:23 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":64,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":197,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":0.0,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:23.069","offline":false}]}
  287. 17.09 04:05:23 INFO  [TransferManager] OperDayMessanger - UserLogOut
  288. 17.09 04:05:23 INFO  [TechProcessImpl] Message  "User Logout" was send, session = SessionEntity [dateBegin=Mon Sep 17 04:05:06 MSK 2018, dateEnd=Mon Sep 17 04:05:23 MSK 2018, user=1 Администратор Администраторович Администраторов526317984689, toString()=ru.crystals.pos.check.SessionEntity@11db]
  289. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  290. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] **********************
  291. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] *Извините,           *
  292. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] *касса не работает   *
  293. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] **********************
  294. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract]
  295. 17.09 04:05:23 INFO  [FilesChecker] Catalog goods transport event
  296. 17.09 04:05:23 INFO  [FilesChecker]    goods types for report count: 0
  297. 17.09 04:05:23 INFO  [FilesChecker]    catalog goods files to cash count: 0
  298. 17.09 04:05:23 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  299. 17.09 04:05:23 INFO  [PasswordLoginContainer] Start LOGIN
  300. 17.09 04:05:23 INFO  [TechProcessImpl] userLogin ru.crystals.pos.user.UserEntity[id=null]
  301. 17.09 04:05:23 INFO  [TechProcessImpl] userLogout
  302. 17.09 04:05:23 INFO  [CommonLogger] getFactory().getTechProcess().isShiftOpen() = true
  303. 17.09 04:05:23 INFO  [CommonLogger] getFactory().getTechProcess().checkUserRight(Right.SHOW_MAIN_MODE)) = true
  304. 17.09 04:05:23 INFO  [PasswordLoginContainer] Finish LOGIN
  305. 17.09 04:05:23 INFO  [SpeedLog] TechProcess authenticating user time = 88 ms
  306. 17.09 04:05:23 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":3,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":0.0,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:23.563","offline":false}]}
  307. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  308. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] **********************
  309. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  310. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  311. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] **********************
  312. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract]
  313. 17.09 04:05:23 INFO  [Scale] BarcodeScannerImpl - barcode = 4680010000007
  314. 17.09 04:05:23 INFO  [TechProcessImpl] eventBarcodeScanner 4680010000007
  315. 17.09 04:05:23 INFO  [CheckContainer] Barcode 4680010000007 has been received by visualisation
  316. 17.09 04:05:23 INFO  [TechProcessImpl] TP searchProduct 4680010000007
  317. 17.09 04:05:23 INFO  [CatalogService] getGoodsByBarCode barcode = 4680010000007
  318. 17.09 04:05:23 INFO  [CatalogService] get product by barcode '4680010000007' result: ProductSpiritsEntity[name=Пиво светлое пенное (Россия), item=80010]
  319. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 4680010000007 time = 3 ms
  320. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 4680010000007 time = 3 ms
  321. 17.09 04:05:23 INFO  [SpeedLog] getProductRestrictions  time = 3 ms
  322. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 4680010000007 time = 6 ms
  323. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 4680010000007 time = 6 ms
  324. 17.09 04:05:23 INFO  [SpeedLog] searchProduct time  time = 6 ms
  325. 17.09 04:05:23 INFO  [TransferManager] OD found 0 transactions to register
  326. 17.09 04:05:23 INFO  [TransferManager] OD found 0 documents to register
  327. 17.09 04:05:23 INFO  [Scale] BarcodeScannerImpl - barcode = 4680010000007
  328. 17.09 04:05:23 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":4,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":0.0,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:23.773","offline":false}]}
  329. 17.09 04:05:23 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,117 sec; average speed = 0,047 sec; position test num = 811.0; prooduct item 80010; <117>
  330. 17.09 04:05:23 INFO  [CommonLogger] busy = false
  331. 17.09 04:05:23 INFO  [TechProcessImpl] eventBarcodeScanner 4680010000007
  332. 17.09 04:05:23 INFO  [CheckContainer] Barcode 4680010000007 has been received by visualisation
  333. 17.09 04:05:23 INFO  [CheckContainer] All conditions are checked. Current position will be added
  334. 17.09 04:05:23 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 80010; type: ProductSpiritsEntity; count: 1000; sum: 253; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  335. 17.09 04:05:23 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":1,"barcode":"4680010000007","item":"80010","name":"Пиво светлое пенное (Россия)","price":2.53,"quant":1.0,"sum":2.53,"sumAll":2.53,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:23.773","offline":false}]}
  336. 17.09 04:05:23 INFO  [SpeedLog] TP addPosition time = 22 ms
  337. 17.09 04:05:23 INFO  [Scale] BarcodeScannerImpl - barcode = 5029053534572
  338. 17.09 04:05:23 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,047 sec; average speed = 0,031 sec; position test num = 274; <47>
  339. 17.09 04:05:23 INFO  [CheckContainer] visualization will start searching product
  340. 17.09 04:05:23 INFO  [TechProcessImpl] TP searchProduct 4680010000007
  341. 17.09 04:05:23 INFO  [CatalogService] getGoodsByBarCode barcode = 4680010000007
  342. 17.09 04:05:23 INFO  [CatalogService] get product by barcode '4680010000007' result: ProductSpiritsEntity[name=Пиво светлое пенное (Россия), item=80010]
  343. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 4680010000007 time = 2 ms
  344. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 4680010000007 time = 2 ms
  345. 17.09 04:05:23 INFO  [SpeedLog] getProductRestrictions  time = 1 ms
  346. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 4680010000007 time = 3 ms
  347. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 4680010000007 time = 3 ms
  348. 17.09 04:05:23 INFO  [SpeedLog] searchProduct time  time = 3 ms
  349. 17.09 04:05:23 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,030 sec; average speed = 0,047 sec; position test num = 812.0; prooduct item 80010; <30>
  350. 17.09 04:05:23 INFO  [CommonLogger] busy = false
  351. 17.09 04:05:23 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":2,"barcode":"4680010000007","item":"80010","name":"Пиво светлое пенное (Россия)","price":2.53,"quant":1.0,"sum":2.53,"sumAll":5.06,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:23.872","offline":false}]}
  352. 17.09 04:05:23 INFO  [Scale] BarcodeScannerImpl - barcode = 5029053534572
  353. 17.09 04:05:23 INFO  [TechProcessImpl] eventBarcodeScanner 5029053534572
  354. 17.09 04:05:23 INFO  [CheckContainer] Barcode 5029053534572 has been received by visualisation
  355. 17.09 04:05:23 INFO  [CheckContainer] All conditions are checked. Current position will be added
  356. 17.09 04:05:23 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 80010; type: ProductSpiritsEntity; count: 1000; sum: 253; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  357. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  358. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] **********************
  359. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] *Пиво светлое  1 2.53*
  360. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] *Итого           5.06*
  361. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract] **********************
  362. 17.09 04:05:23 INFO  [TextCustomerDisplayPluginAbstract]
  363. 17.09 04:05:23 INFO  [SpeedLog] TP addPosition time = 25 ms
  364. 17.09 04:05:23 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,063 sec; average speed = 0,031 sec; position test num = 275; <63>
  365. 17.09 04:05:23 INFO  [CheckContainer] visualization will start searching product
  366. 17.09 04:05:23 INFO  [TechProcessImpl] TP searchProduct 5029053534572
  367. 17.09 04:05:23 INFO  [CatalogService] getGoodsByBarCode barcode = 5029053534572
  368. 17.09 04:05:23 INFO  [CatalogService] get product by barcode '5029053534572' result: ProductPieceEntity[name=Безалкогольный энергетический напиток НеПиво, item=5029053534572]
  369. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5029053534572 time = 2 ms
  370. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5029053534572 time = 2 ms
  371. 17.09 04:05:23 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  372. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5029053534572 time = 2 ms
  373. 17.09 04:05:23 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5029053534572 time = 2 ms
  374. 17.09 04:05:23 INFO  [SpeedLog] searchProduct time  time = 2 ms
  375. 17.09 04:05:23 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,027 sec; average speed = 0,047 sec; position test num = 813.0; prooduct item 5029053534572; <27>
  376. 17.09 04:05:23 INFO  [CommonLogger] busy = false
  377. 17.09 04:05:23 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":3,"barcode":"5029053534572","item":"5029053534572","name":"Безалкогольный энергетический ","price":300.5,"quant":1.0,"sum":300.5,"sumAll":305.56,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:23.976","offline":false}]}
  378. 17.09 04:05:23 INFO  [TechProcessImpl] eventBarcodeScanner 5029053534572
  379. 17.09 04:05:23 INFO  [CheckContainer] Barcode 5029053534572 has been received by visualisation
  380. 17.09 04:05:24 INFO  [CheckContainer] All conditions are checked. Current position will be added
  381. 17.09 04:05:24 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 5029053534572; type: ProductPieceEntity; count: 1000; sum: 30050; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  382. 17.09 04:05:24 INFO  [SpeedLog] TP addPosition time = 25 ms
  383. 17.09 04:05:24 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,040 sec; average speed = 0,031 sec; position test num = 276; <40>
  384. 17.09 04:05:24 INFO  [CheckContainer] visualization will start searching product
  385. 17.09 04:05:24 INFO  [TechProcessImpl] TP searchProduct 5029053534572
  386. 17.09 04:05:24 INFO  [CatalogService] getGoodsByBarCode barcode = 5029053534572
  387. 17.09 04:05:24 INFO  [CatalogService] get product by barcode '5029053534572' result: ProductPieceEntity[name=Безалкогольный энергетический напиток НеПиво, item=5029053534572]
  388. 17.09 04:05:24 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5029053534572 time = 2 ms
  389. 17.09 04:05:24 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5029053534572 time = 2 ms
  390. 17.09 04:05:24 INFO  [SpeedLog] getProductRestrictions  time = 3 ms
  391. 17.09 04:05:24 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5029053534572 time = 6 ms
  392. 17.09 04:05:24 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5029053534572 time = 6 ms
  393. 17.09 04:05:24 INFO  [SpeedLog] searchProduct time  time = 7 ms
  394. 17.09 04:05:24 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":4,"barcode":"5029053534572","item":"5029053534572","name":"Безалкогольный энергетический ","price":300.5,"quant":1.0,"sum":300.5,"sumAll":606.06,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:05:24.059","offline":false}]}
  395. 17.09 04:05:24 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,024 sec; average speed = 0,047 sec; position test num = 814.0; prooduct item 5029053534572; <24>
  396. 17.09 04:05:24 INFO  [CommonLogger] busy = false
  397. 17.09 04:05:24 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=32, command=kbdSubtotal]
  398. 17.09 04:05:24 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 5029053534572; type: ProductPieceEntity; count: 1000; sum: 30050; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  399. 17.09 04:05:24 INFO  [SpeedLog] TP addPosition time = 21 ms
  400. 17.09 04:05:24 INFO  [CommonLogger] busy = true
  401. 17.09 04:05:24 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  402. 17.09 04:05:24 INFO  [TextCustomerDisplayPluginAbstract] **********************
  403. 17.09 04:05:24 INFO  [TextCustomerDisplayPluginAbstract] *Безалкоголь 1 300.50*
  404. 17.09 04:05:24 INFO  [TextCustomerDisplayPluginAbstract] *Итого         606.06*
  405. 17.09 04:05:24 INFO  [TextCustomerDisplayPluginAbstract] **********************
  406. 17.09 04:05:24 INFO  [TextCustomerDisplayPluginAbstract]
  407. 17.09 04:05:24 TRACE [TechProcessImpl] Start warn divide alco
  408. 17.09 04:05:24 TRACE [TechProcessImpl] End warn devide alco
  409. 17.09 04:05:24 INFO  [TechProcessImpl] goToDiscounts
  410. 17.09 04:05:24 INFO  [LoyalBridgeServiceImpl] --------------- begin discount calculation ---------------
  411. 17.09 04:05:24 INFO  [TransferManager] Nothing yet not processed on server to resend
  412. 17.09 04:05:25 INFO  [LoyalProductFinder] Time finding items (2) = 752 ms
  413. 17.09 04:05:25 INFO  [LoyalProductsConverter] Time searching loyal goods for 2 productItems = 752 ms
  414. 17.09 04:05:25 INFO  [LoyalCalculatorConverter] Time converting 2 positions = 0 ms
  415. 17.09 04:05:26 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  416. 17.09 04:05:27 INFO  [FiscalPrinter] resetException()
  417. 17.09 04:05:27 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  418. 17.09 04:05:28 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  419. 17.09 04:05:28 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  420. 17.09 04:05:28 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  421. 17.09 04:05:28 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  422. 17.09 04:05:29 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  423. 17.09 04:05:29 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  424. 17.09 04:05:29 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  425. 17.09 04:05:29 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  426. 17.09 04:05:35 ERROR [LoyaltyRestrictionsServiceImpl] checkRestrictions: failed
  427. org.springframework.web.client.ResourceAccessException: I/O error on POST request for "http://127.0.0.1:50052/v1/check": Read timed out; nested exception is java.net.SocketTimeoutException: Read timed out
  428.     at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:582)
  429.     at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:532)
  430.     at org.springframework.web.client.RestTemplate.postForObject(RestTemplate.java:332)
  431.     at ru.crystals.pos.loyalty.LoyaltyRestrictionsServiceImpl.checkRestrictions(LoyaltyRestrictionsServiceImpl.java:172)
  432.     at ru.crystals.loyal.providers.ClassicSetLoyProvider.process(ClassicSetLoyProvider.java:88)
  433.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.process(LoyProvidersRegistryImpl.java:135)
  434.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.calcDiscounts(LoyalServiceImpl.java:748)
  435.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doLoyalty(LoyalServiceImpl.java:667)
  436.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doDiscount(LoyalServiceImpl.java:766)
  437.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.doDiscount(LoyalBridgeServiceImpl.java:372)
  438.     at ru.crystals.pos.techprocess.TechProcessImpl.applyDiscountsAndGetResult(TechProcessImpl.java:3550)
  439.     at ru.crystals.pos.techprocess.TechProcessImpl.subtotalScenary(TechProcessImpl.java:3113)
  440.     at ru.crystals.pos.visualization.check.CheckContainer.startSubtotalScenary(CheckContainer.java:1477)
  441.     at ru.crystals.pos.visualization.check.CheckContainer.subtotalProcessPurchaseState(CheckContainer.java:1448)
  442.     at ru.crystals.pos.visualization.check.CheckContainer.subtotal(CheckContainer.java:1345)
  443.     at ru.crystals.pos.visualization.components.MainWindow.subTotal(MainWindow.java:833)
  444.     at ru.crystals.pos.visualization.Factory.eventFunctionKey(Factory.java:538)
  445.     at ru.crystals.pos.techprocess.TechProcessImpl.eventFunctionKey(TechProcessImpl.java:4167)
  446.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:165)
  447.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  448.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  449.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  450.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$1(InternalCashPoolExecutorImpl.java:120)
  451.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  452.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  453.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  454.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  455.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  456.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  457.     at java.lang.Thread.run(Thread.java:745)
  458. Caused by: java.net.SocketTimeoutException: Read timed out
  459.     at java.net.SocketInputStream.socketRead0(Native Method)
  460.     at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
  461.     at java.net.SocketInputStream.read(SocketInputStream.java:170)
  462.     at java.net.SocketInputStream.read(SocketInputStream.java:141)
  463.     at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
  464.     at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
  465.     at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
  466.     at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:704)
  467.     at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:647)
  468.     at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1569)
  469.     at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474)
  470.     at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
  471.     at org.springframework.http.client.SimpleClientHttpResponse.getRawStatusCode(SimpleClientHttpResponse.java:48)
  472.     at org.springframework.http.client.AbstractClientHttpResponse.getStatusCode(AbstractClientHttpResponse.java:33)
  473.     at org.springframework.web.client.DefaultResponseErrorHandler.getHttpStatusCode(DefaultResponseErrorHandler.java:56)
  474.     at org.springframework.web.client.DefaultResponseErrorHandler.hasError(DefaultResponseErrorHandler.java:50)
  475.     at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:604)
  476.     at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:572)
  477.     ... 29 more
  478. 17.09 04:05:42 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  479. 17.09 04:05:42 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  480. 17.09 04:05:33 INFO  [FilesChecker] Catalog goods transport event
  481. 17.09 04:05:36 INFO  [TransferManager] Nothing yet not processed on server to resend
  482. 17.09 04:05:42 INFO  [FilesChecker]    goods types for report count: 0
  483. 17.09 04:05:42 INFO  [FilesChecker]    catalog goods files to cash count: 0
  484. 17.09 04:05:42 WARN  [AdvertisingActionUtils] superfluous [1] CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2346;guid=60699;name=Спасибо от Сбербанка;parentGuid=null;masterActions=[];mode=UNCONDITIONAL;worksAnyTime=true;useRestrictions=true;priority=1160.0]) one!
  485. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing CFT-backed bonus discount action [AdvertisingActionEntity:[id=2026;guid=-1506222621;name=РА_Спасибо_до50р;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1320.0]] from further processing 'cause it has no chance to trigger anyway!
  486. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=1989;guid=422993713;name=РА_ЦФТ_исключение10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1050.0]] from further processing 'cause it has no chance to trigger anyway!
  487. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=2474;guid=422993744;name=РА_ЦФТ_исключение20;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1060.0]] from further processing 'cause it has no chance to trigger anyway!
  488. 17.09 04:05:42 WARN  [AdvertisingActionUtils] superfluous [2] BONUS_CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=3189;guid=1935033882;name=РА_ЦФТ_без_ограничений;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1070.0]) one!
  489. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=2926;guid=1270000641;name=SET10BONUSES: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=10.0]] from further processing 'cause it has no chance to trigger anyway!
  490. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3759;guid=58449;name=SR-2252_AdvAct_WriteoffBonuses;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1020.0]] from further processing 'cause it has no chance to trigger anyway!
  491. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3318;guid=61192;name=SR-2185: Автоматическое списание бонусов SET10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1170.0]] from further processing 'cause it has no chance to trigger anyway!
  492. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=1895;guid=-833406141;name=SR-1177: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=2000.0]] from further processing 'cause it has no chance to trigger anyway!
  493. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=3704;guid=59275;name=Бонусы Лента списание;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1080.0]] from further processing 'cause it has no chance to trigger anyway!
  494. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=2334;guid=-6683376;name=Lenta_cobranding_decrement-CR-1019;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1505.0]] from further processing 'cause it has no chance to trigger anyway!
  495. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_LOYMAX-backed bonus discount action [AdvertisingActionEntity:[id=2046;guid=61281;name=Списание бонусных баллов LOYMAX;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1180.0]] from further processing 'cause it has no chance to trigger anyway!
  496. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=2926;guid=1270000641;name=SET10BONUSES: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=10.0]] from further processing 'cause it has no chance to trigger anyway!
  497. 17.09 04:05:42 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  498. 17.09 04:05:42 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  499. 17.09 04:05:42 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  500. 17.09 04:05:42 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  501. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3759;guid=58449;name=SR-2252_AdvAct_WriteoffBonuses;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1020.0]] from further processing 'cause it has no chance to trigger anyway!
  502. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=1989;guid=422993713;name=РА_ЦФТ_исключение10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1050.0]] from further processing 'cause it has no chance to trigger anyway!
  503. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=2474;guid=422993744;name=РА_ЦФТ_исключение20;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1060.0]] from further processing 'cause it has no chance to trigger anyway!
  504. 17.09 04:05:42 WARN  [AdvertisingActionUtils] superfluous [0] BONUS_CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=3189;guid=1935033882;name=РА_ЦФТ_без_ограничений;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1070.0]) one!
  505. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=3704;guid=59275;name=Бонусы Лента списание;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1080.0]] from further processing 'cause it has no chance to trigger anyway!
  506. 17.09 04:05:42 WARN  [AdvertisingActionUtils] superfluous [0] CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2346;guid=60699;name=Спасибо от Сбербанка;parentGuid=null;masterActions=[];mode=UNCONDITIONAL;worksAnyTime=true;useRestrictions=true;priority=1160.0]) one!
  507. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3318;guid=61192;name=SR-2185: Автоматическое списание бонусов SET10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1170.0]] from further processing 'cause it has no chance to trigger anyway!
  508. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_LOYMAX-backed bonus discount action [AdvertisingActionEntity:[id=2046;guid=61281;name=Списание бонусных баллов LOYMAX;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1180.0]] from further processing 'cause it has no chance to trigger anyway!
  509. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing CFT-backed bonus discount action [AdvertisingActionEntity:[id=2026;guid=-1506222621;name=РА_Спасибо_до50р;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1320.0]] from further processing 'cause it has no chance to trigger anyway!
  510. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=2334;guid=-6683376;name=Lenta_cobranding_decrement-CR-1019;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1505.0]] from further processing 'cause it has no chance to trigger anyway!
  511. 17.09 04:05:42 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=1895;guid=-833406141;name=SR-1177: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=2000.0]] from further processing 'cause it has no chance to trigger anyway!
  512. 17.09 04:05:42 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  513. 17.09 04:05:43 TRACE [LoyPluginEmulator] entering doDiscount(Receipt). The argument is: ru.crystals.api.commons.ReceiptPurchaseWrapper@1845446
  514. 17.09 04:05:43 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  515. 17.09 04:05:43 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  516. 17.09 04:05:43 TRACE [LoyPluginEmulator] leaving readProperties(IntegrationProperties, Logger). The result is: LoyPluginEmulatorProperties{primaryCalcUrl=http://127.0.0.1:10065/loy-plugin-processing/emulator/process, secondaryCalcUrl=null, feedbackUrl=http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback, connectionTimeout=1000, readTimeout=1000, quiet=false, cardProcessingId='null'}; it took 1 [ms]
  517. 17.09 04:05:43 TRACE [LoyPluginEmulator] entering makeCalcCalls(List, EmulatorReceipt). The arguments are: urls: [http://127.0.0.1:10065/loy-plugin-processing/emulator/process], emulatorReceipt: emul-receipt [card: null; positions: [emul-pos [no: 1; marking: "80010"; qnty: 2000; sum: 506; min-sum: 0; discountable: true], emul-pos [no: 2; marking: "5029053534572"; qnty: 2000; sum: 60100; min-sum: 0; discountable: true]]]
  518. 17.09 04:05:45 ERROR [LoyPluginEmulator] makeCalcCalls() failed
  519. java.net.SocketTimeoutException: Read timed out
  520.     at java.net.SocketInputStream.socketRead0(Native Method)
  521.     at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
  522.     at java.net.SocketInputStream.read(SocketInputStream.java:170)
  523.     at java.net.SocketInputStream.read(SocketInputStream.java:141)
  524.     at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
  525.     at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
  526.     at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
  527.     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
  528.     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
  529.     at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
  530.     at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
  531.     at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
  532.     at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
  533.     at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
  534.     at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
  535.     at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
  536.     at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
  537.     at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
  538.     at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
  539.     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
  540.     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
  541.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.makeCalcCalls(LoyPluginEmulator.java:359)
  542.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.doDiscount(LoyPluginEmulator.java:121)
  543.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.process(SetApiPluginLoyProvider.java:132)
  544.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.process(LoyProvidersRegistryImpl.java:135)
  545.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.calcDiscounts(LoyalServiceImpl.java:748)
  546.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doLoyalty(LoyalServiceImpl.java:667)
  547.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doDiscount(LoyalServiceImpl.java:766)
  548.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.doDiscount(LoyalBridgeServiceImpl.java:372)
  549.     at ru.crystals.pos.techprocess.TechProcessImpl.applyDiscountsAndGetResult(TechProcessImpl.java:3550)
  550.     at ru.crystals.pos.techprocess.TechProcessImpl.subtotalScenary(TechProcessImpl.java:3113)
  551.     at ru.crystals.pos.visualization.check.CheckContainer.startSubtotalScenary(CheckContainer.java:1477)
  552.     at ru.crystals.pos.visualization.check.CheckContainer.subtotalProcessPurchaseState(CheckContainer.java:1448)
  553.     at ru.crystals.pos.visualization.check.CheckContainer.subtotal(CheckContainer.java:1345)
  554.     at ru.crystals.pos.visualization.components.MainWindow.subTotal(MainWindow.java:833)
  555.     at ru.crystals.pos.visualization.Factory.eventFunctionKey(Factory.java:538)
  556.     at ru.crystals.pos.techprocess.TechProcessImpl.eventFunctionKey(TechProcessImpl.java:4167)
  557.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:165)
  558.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  559.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  560.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  561.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$1(InternalCashPoolExecutorImpl.java:120)
  562.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  563.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  564.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  565.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  566.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  567.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  568.     at java.lang.Thread.run(Thread.java:745)
  569. 17.09 04:05:45 ERROR [LoyPluginEmulator] makeCalcCalls: exception caught!
  570. java.net.SocketTimeoutException: Read timed out
  571.     at java.net.SocketInputStream.socketRead0(Native Method)
  572.     at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
  573.     at java.net.SocketInputStream.read(SocketInputStream.java:170)
  574.     at java.net.SocketInputStream.read(SocketInputStream.java:141)
  575.     at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
  576.     at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
  577.     at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
  578.     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
  579.     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
  580.     at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
  581.     at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
  582.     at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
  583.     at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
  584.     at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
  585.     at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
  586.     at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
  587.     at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
  588.     at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
  589.     at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
  590.     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
  591.     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
  592.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.makeCalcCalls(LoyPluginEmulator.java:359)
  593.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.doDiscount(LoyPluginEmulator.java:121)
  594.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.process(SetApiPluginLoyProvider.java:132)
  595.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.process(LoyProvidersRegistryImpl.java:135)
  596.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.calcDiscounts(LoyalServiceImpl.java:748)
  597.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doLoyalty(LoyalServiceImpl.java:667)
  598.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doDiscount(LoyalServiceImpl.java:766)
  599.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.doDiscount(LoyalBridgeServiceImpl.java:372)
  600.     at ru.crystals.pos.techprocess.TechProcessImpl.applyDiscountsAndGetResult(TechProcessImpl.java:3550)
  601.     at ru.crystals.pos.techprocess.TechProcessImpl.subtotalScenary(TechProcessImpl.java:3113)
  602.     at ru.crystals.pos.visualization.check.CheckContainer.startSubtotalScenary(CheckContainer.java:1477)
  603.     at ru.crystals.pos.visualization.check.CheckContainer.subtotalProcessPurchaseState(CheckContainer.java:1448)
  604.     at ru.crystals.pos.visualization.check.CheckContainer.subtotal(CheckContainer.java:1345)
  605.     at ru.crystals.pos.visualization.components.MainWindow.subTotal(MainWindow.java:833)
  606.     at ru.crystals.pos.visualization.Factory.eventFunctionKey(Factory.java:538)
  607.     at ru.crystals.pos.techprocess.TechProcessImpl.eventFunctionKey(TechProcessImpl.java:4167)
  608.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:165)
  609.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  610.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  611.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  612.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$1(InternalCashPoolExecutorImpl.java:120)
  613.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  614.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  615.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  616.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  617.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  618.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  619.     at java.lang.Thread.run(Thread.java:745)
  620. 17.09 04:05:45 WARN  [LoyPluginEmulator] leaving makeCalcCalls(List, EmulatorReceipt). NO CONNECTION; it took 2243 [ms]
  621. 17.09 04:05:45 ERROR [LoyPluginEmulator] doDiscount: exception caught!
  622. java.net.SocketTimeoutException: Read timed out
  623.     at java.net.SocketInputStream.socketRead0(Native Method)
  624.     at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
  625.     at java.net.SocketInputStream.read(SocketInputStream.java:170)
  626.     at java.net.SocketInputStream.read(SocketInputStream.java:141)
  627.     at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
  628.     at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
  629.     at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
  630.     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
  631.     at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
  632.     at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
  633.     at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
  634.     at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
  635.     at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
  636.     at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
  637.     at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
  638.     at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
  639.     at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
  640.     at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
  641.     at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
  642.     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
  643.     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
  644.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.makeCalcCalls(LoyPluginEmulator.java:359)
  645.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.doDiscount(LoyPluginEmulator.java:121)
  646.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.process(SetApiPluginLoyProvider.java:132)
  647.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.process(LoyProvidersRegistryImpl.java:135)
  648.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.calcDiscounts(LoyalServiceImpl.java:748)
  649.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doLoyalty(LoyalServiceImpl.java:667)
  650.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doDiscount(LoyalServiceImpl.java:766)
  651.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.doDiscount(LoyalBridgeServiceImpl.java:372)
  652.     at ru.crystals.pos.techprocess.TechProcessImpl.applyDiscountsAndGetResult(TechProcessImpl.java:3550)
  653.     at ru.crystals.pos.techprocess.TechProcessImpl.subtotalScenary(TechProcessImpl.java:3113)
  654.     at ru.crystals.pos.visualization.check.CheckContainer.startSubtotalScenary(CheckContainer.java:1477)
  655.     at ru.crystals.pos.visualization.check.CheckContainer.subtotalProcessPurchaseState(CheckContainer.java:1448)
  656.     at ru.crystals.pos.visualization.check.CheckContainer.subtotal(CheckContainer.java:1345)
  657.     at ru.crystals.pos.visualization.components.MainWindow.subTotal(MainWindow.java:833)
  658.     at ru.crystals.pos.visualization.Factory.eventFunctionKey(Factory.java:538)
  659.     at ru.crystals.pos.techprocess.TechProcessImpl.eventFunctionKey(TechProcessImpl.java:4167)
  660.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:165)
  661.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  662.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  663.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  664.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$1(InternalCashPoolExecutorImpl.java:120)
  665.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  666.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  667.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  668.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  669.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  670.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  671.     at java.lang.Thread.run(Thread.java:745)
  672. 17.09 04:05:45 TRACE [API] showDialogForm text1=Повторить, text2=Отмена
  673. 17.09 04:05:45 ERROR [LoyalServiceImpl] Error discount calculation for purchase PurchaseEntity [id=4545, number=197, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  674. java.lang.NullPointerException
  675.     at ru.crystals.spi.adapters.UIFormsGetter.showDialogForm(UIFormsGetter.java:77)
  676.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.showYesNoDislogAndWait(LoyPluginEmulator.java:211)
  677.     at ru.crystals.emulator.loy.plugin.LoyPluginEmulator.doDiscount(LoyPluginEmulator.java:130)
  678.     at ru.crystals.pos.loyal.SetApiPluginLoyProvider.process(SetApiPluginLoyProvider.java:132)
  679.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.process(LoyProvidersRegistryImpl.java:135)
  680.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.calcDiscounts(LoyalServiceImpl.java:748)
  681.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doLoyalty(LoyalServiceImpl.java:667)
  682.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doDiscount(LoyalServiceImpl.java:766)
  683.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.doDiscount(LoyalBridgeServiceImpl.java:372)
  684.     at ru.crystals.pos.techprocess.TechProcessImpl.applyDiscountsAndGetResult(TechProcessImpl.java:3550)
  685.     at ru.crystals.pos.techprocess.TechProcessImpl.subtotalScenary(TechProcessImpl.java:3113)
  686.     at ru.crystals.pos.visualization.check.CheckContainer.startSubtotalScenary(CheckContainer.java:1477)
  687.     at ru.crystals.pos.visualization.check.CheckContainer.subtotalProcessPurchaseState(CheckContainer.java:1448)
  688.     at ru.crystals.pos.visualization.check.CheckContainer.subtotal(CheckContainer.java:1345)
  689.     at ru.crystals.pos.visualization.components.MainWindow.subTotal(MainWindow.java:833)
  690.     at ru.crystals.pos.visualization.Factory.eventFunctionKey(Factory.java:538)
  691.     at ru.crystals.pos.techprocess.TechProcessImpl.eventFunctionKey(TechProcessImpl.java:4167)
  692.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:165)
  693.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  694.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  695.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  696.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$1(InternalCashPoolExecutorImpl.java:120)
  697.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  698.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  699.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  700.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  701.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  702.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  703.     at java.lang.Thread.run(Thread.java:745)
  704. 17.09 04:05:45 INFO  [LoyalBridgeServiceImpl] Total time of discount calculation = 20946 ms
  705. 17.09 04:05:45 INFO  [LoyalBridgeServiceImpl] ---------------- end discount calculation ----------------
  706. 17.09 04:05:45 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  707. 17.09 04:05:45 INFO  [TextCustomerDisplayPluginAbstract] **********************
  708. 17.09 04:05:45 INFO  [TextCustomerDisplayPluginAbstract] *Скидка          0.00*
  709. 17.09 04:05:45 INFO  [TextCustomerDisplayPluginAbstract] *Итого         606.06*
  710. 17.09 04:05:45 INFO  [TextCustomerDisplayPluginAbstract] **********************
  711. 17.09 04:05:45 INFO  [TextCustomerDisplayPluginAbstract]
  712. 17.09 04:05:45 INFO  [SpeedLog] TechProcess discounts processing on cheque with 2 positions [sale] time = 20994 ms
  713. 17.09 04:05:45 INFO  [CommonLogger] value = 0
  714. 17.09 04:05:45 WARN  [HibernateBackedLoyTxDao] leaving getLoyTxByReceipt(PurchaseEntity): at least one of the mandaroty fields (either doc-num: null, or operation-type: true, or shop-num: null, or shift-num: null, or cash-num: null) of the receipt [PurchaseEntity [id=4545, number=null, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]] is NULL! So, NULL will be returned!
  715. 17.09 04:05:45 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  716. 17.09 04:05:47 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
  717. 17.09 04:05:47 INFO  [PendingOperationQueue] No pending card operations found.
  718. 17.09 04:05:48 INFO  [CommonLogger] Starting cleaning. All log records older than 19 июня 2018 04:05:48 will be deleted.
  719. 17.09 04:05:48 INFO  [LoyProvidersRegistryImpl] Resend stale feedback
  720. 17.09 04:05:48 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = SetApiLoyaltyPlugin
  721. 17.09 04:05:45 TRACE [TechProcessImpl] Start warn divide amount
  722. 17.09 04:05:48 DEBUG [TechProcessImpl] Server online mode
  723. 17.09 04:05:48 INFO  [TechProcessImpl] goToPayments
  724. 17.09 04:05:48 INFO  [LoyProvidersRegistryImpl] There is no stale feedback for SetApiLoyaltyPlugin
  725. 17.09 04:05:48 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = set-loy-provider
  726. 17.09 04:05:48 INFO  [LoyProvidersRegistryImpl] There is no stale feedback for set-loy-provider
  727. 17.09 04:05:48 INFO  [CommonLogger] Cleaning done.
  728. 17.09 04:05:48 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  729. 17.09 04:05:48 INFO  [TextCustomerDisplayPluginAbstract] **********************
  730. 17.09 04:05:48 INFO  [TextCustomerDisplayPluginAbstract] *Скидка          0.00*
  731. 17.09 04:05:48 INFO  [TextCustomerDisplayPluginAbstract] *Итого         606.06*
  732. 17.09 04:05:48 INFO  [TextCustomerDisplayPluginAbstract] **********************
  733. 17.09 04:05:48 INFO  [TextCustomerDisplayPluginAbstract]
  734. 17.09 04:05:48 INFO  [CheckContainer] startPayments() surcharge = 60606
  735. 17.09 04:05:48 INFO  [CheckContainer] isPaymentComplete = false
  736. 17.09 04:05:48 INFO  [CheckContainer] prevState = ADD_POSITION
  737. 17.09 04:05:48 INFO  [CheckContainer] paid = 0
  738. 17.09 04:05:48 INFO  [CheckContainer] surcharge = 60606
  739. 17.09 04:05:48 INFO  [CheckContainer] getPaymentFiscalizeError = NONE
  740. 17.09 04:05:48 INFO  [CheckContainer] Current payment container is ru.crystals.pos.visualization.payments.cash.CashPaymentContainer
  741. 17.09 04:05:48 INFO  [CommonLogger] busy = false
  742. 17.09 04:05:48 INFO  [SpeedLog] (SUBTOTAL) time = 24,642;
  743. 17.09 04:05:48 INFO  [CommonLogger] busy = false
  744. 17.09 04:05:52 INFO  [FilesChecker] Catalog goods transport event
  745. 17.09 04:05:52 INFO  [FilesChecker]    goods types for report count: 0
  746. 17.09 04:05:52 INFO  [FilesChecker]    catalog goods files to cash count: 0
  747. 17.09 04:05:54 INFO  [TransferManager] Nothing yet not processed on server to resend
  748. 17.09 04:05:58 INFO  [TransferManager] Message [userLogOut] has been sent
  749. 17.09 04:05:59 INFO  [TransferManager] Message [userLogOut] has been sent
  750. 17.09 04:06:01 INFO  [FiscalPrinter] resetException()
  751. 17.09 04:06:01 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=82, command=kbdMenu3]
  752. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [1] CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2346;guid=60699;name=Спасибо от Сбербанка;parentGuid=null;masterActions=[];mode=UNCONDITIONAL;worksAnyTime=true;useRestrictions=true;priority=1160.0]) one!
  753. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing CFT-backed bonus discount action [AdvertisingActionEntity:[id=2026;guid=-1506222621;name=РА_Спасибо_до50р;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1320.0]] from further processing 'cause it has no chance to trigger anyway!
  754. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [2] BONUS_CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=1989;guid=422993713;name=РА_ЦФТ_исключение10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1050.0]) one!
  755. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=2474;guid=422993744;name=РА_ЦФТ_исключение20;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1060.0]] from further processing 'cause it has no chance to trigger anyway!
  756. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=3189;guid=1935033882;name=РА_ЦФТ_без_ограничений;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1070.0]] from further processing 'cause it has no chance to trigger anyway!
  757. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [3] BONUS_SR10-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2926;guid=1270000641;name=SET10BONUSES: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=10.0]) one!
  758. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3759;guid=58449;name=SR-2252_AdvAct_WriteoffBonuses;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1020.0]] from further processing 'cause it has no chance to trigger anyway!
  759. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3318;guid=61192;name=SR-2185: Автоматическое списание бонусов SET10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1170.0]] from further processing 'cause it has no chance to trigger anyway!
  760. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=1895;guid=-833406141;name=SR-1177: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=2000.0]] from further processing 'cause it has no chance to trigger anyway!
  761. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [1] BONUS_INFORMIX-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=3704;guid=59275;name=Бонусы Лента списание;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1080.0]) one!
  762. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=2334;guid=-6683376;name=Lenta_cobranding_decrement-CR-1019;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1505.0]] from further processing 'cause it has no chance to trigger anyway!
  763. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [0] BONUS_LOYMAX-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2046;guid=61281;name=Списание бонусных баллов LOYMAX;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1180.0]) one!
  764. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [1] CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2346;guid=60699;name=Спасибо от Сбербанка;parentGuid=null;masterActions=[];mode=UNCONDITIONAL;worksAnyTime=true;useRestrictions=true;priority=1160.0]) one!
  765. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing CFT-backed bonus discount action [AdvertisingActionEntity:[id=2026;guid=-1506222621;name=РА_Спасибо_до50р;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1320.0]] from further processing 'cause it has no chance to trigger anyway!
  766. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [2] BONUS_CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=1989;guid=422993713;name=РА_ЦФТ_исключение10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1050.0]) one!
  767. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=2474;guid=422993744;name=РА_ЦФТ_исключение20;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1060.0]] from further processing 'cause it has no chance to trigger anyway!
  768. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=3189;guid=1935033882;name=РА_ЦФТ_без_ограничений;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1070.0]] from further processing 'cause it has no chance to trigger anyway!
  769. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [3] BONUS_SR10-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2926;guid=1270000641;name=SET10BONUSES: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=10.0]) one!
  770. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3759;guid=58449;name=SR-2252_AdvAct_WriteoffBonuses;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1020.0]] from further processing 'cause it has no chance to trigger anyway!
  771. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3318;guid=61192;name=SR-2185: Автоматическое списание бонусов SET10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1170.0]] from further processing 'cause it has no chance to trigger anyway!
  772. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=1895;guid=-833406141;name=SR-1177: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=2000.0]] from further processing 'cause it has no chance to trigger anyway!
  773. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [1] BONUS_INFORMIX-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=3704;guid=59275;name=Бонусы Лента списание;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1080.0]) one!
  774. 17.09 04:06:01 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=2334;guid=-6683376;name=Lenta_cobranding_decrement-CR-1019;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1505.0]] from further processing 'cause it has no chance to trigger anyway!
  775. 17.09 04:06:01 WARN  [AdvertisingActionUtils] superfluous [0] BONUS_LOYMAX-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2046;guid=61281;name=Списание бонусных баллов LOYMAX;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1180.0]) one!
  776. 17.09 04:06:01 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  777. 17.09 04:06:01 INFO  [CommonLogger] Menu command: Смена пользователя (class ru.crystals.pos.visualization.menu.commands.ChangeUserCommand)
  778. 17.09 04:06:01 INFO  [TechProcessImpl] userLogout
  779. 17.09 04:06:01 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":63,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":197,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":606.06,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:01.547","offline":false}]}
  780. 17.09 04:06:01 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  781. 17.09 04:06:01 INFO  [TextCustomerDisplayPluginAbstract] **********************
  782. 17.09 04:06:01 INFO  [TextCustomerDisplayPluginAbstract] *Извините,           *
  783. 17.09 04:06:01 INFO  [TextCustomerDisplayPluginAbstract] *касса не работает   *
  784. 17.09 04:06:01 INFO  [TextCustomerDisplayPluginAbstract] **********************
  785. 17.09 04:06:01 INFO  [TextCustomerDisplayPluginAbstract]
  786. 17.09 04:06:01 INFO  [TransferManager] OperDayMessanger - UserLogOut
  787. 17.09 04:06:01 INFO  [TechProcessImpl] Message  "User Logout" was send, session = SessionEntity [dateBegin=Mon Sep 17 04:05:23 MSK 2018, dateEnd=Mon Sep 17 04:06:01 MSK 2018, user=2 Кассир Кассирович Кассиров, toString()=ru.crystals.pos.check.SessionEntity@11dc]
  788. 17.09 04:06:01 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=27, command=kbdCancel]
  789. 17.09 04:06:02 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  790. 17.09 04:06:02 INFO  [PasswordLoginContainer] Start LOGIN
  791. 17.09 04:06:02 INFO  [TechProcessImpl] userLogin ru.crystals.pos.user.UserEntity[id=null]
  792. 17.09 04:06:02 INFO  [TechProcessImpl] userLogout
  793. 17.09 04:06:02 INFO  [FilesChecker] Catalog goods transport event
  794. 17.09 04:06:02 INFO  [FilesChecker]    goods types for report count: 0
  795. 17.09 04:06:02 INFO  [FilesChecker]    catalog goods files to cash count: 0
  796. 17.09 04:06:06 INFO  [CommonLogger] getFactory().getTechProcess().isShiftOpen() = true
  797. 17.09 04:06:06 INFO  [CommonLogger] getFactory().getTechProcess().checkUserRight(Right.SHOW_MAIN_MODE)) = true
  798. 17.09 04:06:06 INFO  [PasswordLoginContainer] Finish LOGIN
  799. 17.09 04:06:06 INFO  [SpeedLog] TechProcess authenticating user time = 4157 ms
  800. 17.09 04:06:06 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":203,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":197,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":606.06,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:06.312","offline":false}]}
  801. 17.09 04:06:06 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  802. 17.09 04:06:06 INFO  [TextCustomerDisplayPluginAbstract] **********************
  803. 17.09 04:06:06 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  804. 17.09 04:06:06 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  805. 17.09 04:06:06 INFO  [TextCustomerDisplayPluginAbstract] **********************
  806. 17.09 04:06:06 INFO  [TextCustomerDisplayPluginAbstract]
  807. 17.09 04:06:06 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=69, command=kbdMenu2]
  808. 17.09 04:06:06 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  809. 17.09 04:06:06 INFO  [TransferManager] Nothing yet not processed on server to resend
  810. 17.09 04:06:06 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  811. 17.09 04:06:07 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  812. 17.09 04:06:07 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  813. 17.09 04:06:07 INFO  [CommonLogger] Menu command: Аннулирование (class ru.crystals.pos.visualization.menu.commands.CancelCheckCommand)
  814. 17.09 04:06:07 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=37, command=kbdLeft]
  815. 17.09 04:06:08 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  816. 17.09 04:06:08 INFO  [TechProcessShiftProxy] cancelCheck start
  817. 17.09 04:06:08 TRACE [ExternalProcessingsImpl] seems that this cash is not aware of existence of CFT-backed loyality programms. So, there is no need to cancel CFT-backed bonuses charge-offs
  818. 17.09 04:06:08 TRACE [ExternalProcessingsImpl] seems that this cash is not aware of existence of CFT-backed loyality programms. So, there is no need to cancel CFT-backed bonuses charge-offs
  819. 17.09 04:06:08 TRACE [ExternalProcessingsImpl] Discounts cancelled: no implementation of PlastekServices.
  820. 17.09 04:06:08 TRACE [ExternalProcessingsImpl] entering discountCancelledToSet5(PurchaseEntity)
  821. 17.09 04:06:08 TRACE [ExternalProcessingsImpl] leaving discountCancelledToSet5(PurchaseEntity): the SET5 loy processing is disabled
  822. 17.09 04:06:08 WARN  [HibernateBackedLoyTxDao] leaving getLoyTxByReceipt(PurchaseEntity): at least one of the mandaroty fields (either doc-num: null, or operation-type: true, or shop-num: null, or shift-num: null, or cash-num: null) of the receipt [PurchaseEntity [id=4545, number=null, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]] is NULL! So, NULL will be returned!
  823. 17.09 04:06:08 WARN  [SetApiPluginLoyProvider] No loyal transaction entity found for purchase PurchaseEntity [id=4545, number=null, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  824. 17.09 04:06:08 INFO  [TechProcessShiftProxy] cancelCheck PurchaseEntity [id=4545, number=null, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  825. 17.09 04:06:08 INFO  [WaitComponent] [WaitComponent] MainFrame enabled - false
  826. 17.09 04:06:08 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  827. 17.09 04:06:08 INFO  [TextCustomerDisplayPluginAbstract] **********************
  828. 17.09 04:06:08 INFO  [TextCustomerDisplayPluginAbstract] *Аннулирование чека  *
  829. 17.09 04:06:08 INFO  [TextCustomerDisplayPluginAbstract] *Сумма чека    606.06*
  830. 17.09 04:06:08 INFO  [TextCustomerDisplayPluginAbstract] **********************
  831. 17.09 04:06:08 INFO  [TextCustomerDisplayPluginAbstract]
  832. 17.09 04:06:08 TRACE [ExternalProcessingsImpl] Purchase cancelled: no implementation of PlastekServices.
  833. 17.09 04:06:08 TRACE [MLServiceImpl] entering getMlCardNo(PurchaseEntity). The argument is: PurchaseEntity [id=4545, number=197, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  834. 17.09 04:06:08 TRACE [MLServiceImpl] leaving getMlCardNo(PurchaseEntity). The result is: null
  835. 17.09 04:06:08 INFO  [FiscalPrinter] printCheck
  836. 17.09 04:06:08 INFO  [FiscalPrinter] Fiscal interrupt: null
  837. 17.09 04:06:08 INFO  [FiscalPrinter] Get document template /mnt/sda1/tce/storage/crystal-cash/modules/fiscalPrinter/templates/check-sale-annul.xml
  838. 17.09 04:06:08 INFO  [DocumentTemplate] =====logo=====
  839. 17.09 04:06:08 INFO  [DocumentTemplate] content: null
  840. 17.09 04:06:08 INFO  [DocumentTemplate] =====header=====
  841. 17.09 04:06:08 INFO  [DocumentTemplate]                    jr. name                   ||NORMAL
  842. 17.09 04:06:08 INFO  [DocumentTemplate]          199100, Spb, Savushkina, 112         ||NORMAL
  843. 17.09 04:06:08 INFO  [DocumentTemplate] ----------------------------------------      ||NORMAL
  844. 17.09 04:06:08 INFO  [DocumentTemplate] Смена:15                     ЭКЛЗ:a454701d-72f||NORMAL
  845. 17.09 04:06:08 INFO  [DocumentTemplate] Номер кассы:60                ИНН:  7802781104||NORMAL
  846. 17.09 04:06:08 INFO  [DocumentTemplate] Кассир:Кассиров Кассир Кассирович             ||NORMAL
  847. 17.09 04:06:08 INFO  [DocumentTemplate] ----------------------------------------      ||NORMAL
  848. 17.09 04:06:08 INFO  [DocumentTemplate] КАССОВЫЙ ЧЕК            197  17-09-2018  04:06||NORMAL
  849. 17.09 04:06:08 INFO  [DocumentTemplate] ----------------------------------------      ||NORMAL
  850. 17.09 04:06:08 INFO  [DocumentTemplate] =====position=====
  851. 17.09 04:06:08 INFO  [DocumentTemplate] Пиво светлое пенное (Ро    2.53*     2   =5.06||SMALL
  852. 17.09 04:06:08 INFO  [DocumentTemplate] Безалкогольный энергети  300.50*     2 =601.00||SMALL
  853. 17.09 04:06:08 INFO  [DocumentTemplate] =====fiscal=====
  854. 17.09 04:06:08 INFO  [DocumentTemplate] content: null
  855. 17.09 04:06:08 INFO  [DocumentTemplate] =====footer=====
  856. 17.09 04:06:08 INFO  [DocumentTemplate]  ******************************************** ||NORMAL
  857. 17.09 04:06:08 INFO  [DocumentTemplate] ЧЕК No.197 АННУЛИРОВАН||DOUBLEHEIGHT
  858. 17.09 04:06:08 INFO  [DocumentTemplate]  ******************************************** ||NORMAL
  859. 17.09 04:06:08 INFO  [DocumentTemplate] =====cut=====
  860. 17.09 04:06:08 INFO  [DocumentTemplate] content: null
  861. 17.09 04:06:11 INFO  [FiscalPrinter] getCountAnnul
  862. 17.09 04:06:11 INFO  [FiscalPrinter] CountAnnul = 14
  863. 17.09 04:06:11 INFO  [FiscalPrinter] getLastDocNum
  864. 17.09 04:06:11 INFO  [TransferManager] ping = true
  865. 17.09 04:06:12 INFO  [FilesChecker] Catalog goods transport event
  866. 17.09 04:06:12 INFO  [FilesChecker]    goods types for report count: 0
  867. 17.09 04:06:12 INFO  [FilesChecker]    catalog goods files to cash count: 0
  868. 17.09 04:06:14 INFO  [CheckServiceImpl] cancelCheck: PurchaseEntity [id=4545, number=197, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=Mon Sep 17 04:06:14 MSK 2018, fiscalDocNum=14;782, sentToServerStatus=NO_SENT]
  869. 17.09 04:06:15 TRACE [ExternalProcessingsImpl] seems that this cash is not aware of existence of CFT-backed loyality programms. So, there is no need to cancel CFT-backed bonuses charge-offs
  870. 17.09 04:06:15 TRACE [ExternalProcessingsImpl] seems that this cash is not aware of existence of CFT-backed loyality programms. So, there is no need to cancel CFT-backed bonuses charge-offs
  871. 17.09 04:06:15 TRACE [ExternalProcessingsImpl] Discounts cancelled: no implementation of PlastekServices.
  872. 17.09 04:06:15 TRACE [ExternalProcessingsImpl] entering discountCancelledToSet5(PurchaseEntity)
  873. 17.09 04:06:15 TRACE [ExternalProcessingsImpl] leaving discountCancelledToSet5(PurchaseEntity): the SET5 loy processing is disabled
  874. 17.09 04:06:15 WARN  [SetApiPluginLoyProvider] No loyal transaction entity found for purchase PurchaseEntity [id=4545, number=197, dateCreate=Mon Sep 17 04:05:23 MSK 2018, dateCommit=Mon Sep 17 04:06:14 MSK 2018, fiscalDocNum=14;782, sentToServerStatus=NO_SENT]
  875. 17.09 04:06:15 INFO  [CommonLogger] value = 0
  876. 17.09 04:06:15 INFO  [TechProcessImpl] Select seller [null]
  877. 17.09 04:06:15 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":25,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":197,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":606.06,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:15.011","offline":false}]}
  878. 17.09 04:06:15 INFO  [SpeedLog] TechProcess cancelCheck time = 6833 ms
  879. 17.09 04:06:15 INFO  [WaitComponent] [WaitComponent] MainFrame enabled - true
  880. 17.09 04:06:15 INFO  [TechProcessImpl] Select seller [null]
  881. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  882. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] **********************
  883. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  884. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  885. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] **********************
  886. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract]
  887. 17.09 04:06:15 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  888. 17.09 04:06:15 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  889. 17.09 04:06:15 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=82, command=kbdMenu3]
  890. 17.09 04:06:15 ERROR [CFTBonusModel] getChargedOffBonusCards: either "receipt" [null], or "sponsorId" [BONUS_CFT] argument is NULL
  891. 17.09 04:06:15 ERROR [CFTBonusModel] getChargedOffBonusCards: either "receipt" [null], or "sponsorId" [BONUS_CFT] argument is NULL
  892. 17.09 04:06:15 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  893. 17.09 04:06:15 INFO  [CommonLogger] Menu command: Смена пользователя (class ru.crystals.pos.visualization.menu.commands.ChangeUserCommand)
  894. 17.09 04:06:15 INFO  [TechProcessImpl] userLogout
  895. 17.09 04:06:15 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":64,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":198,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":0.0,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:15.686","offline":false}]}
  896. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  897. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] **********************
  898. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] *Извините,           *
  899. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] *касса не работает   *
  900. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract] **********************
  901. 17.09 04:06:15 INFO  [TextCustomerDisplayPluginAbstract]
  902. 17.09 04:06:15 INFO  [TransferManager] OperDayMessanger - UserLogOut
  903. 17.09 04:06:15 INFO  [TechProcessImpl] Message  "User Logout" was send, session = SessionEntity [dateBegin=Mon Sep 17 04:06:02 MSK 2018, dateEnd=Mon Sep 17 04:06:15 MSK 2018, user=1 Администратор Администраторович Администраторов526317984689, toString()=ru.crystals.pos.check.SessionEntity@11dd]
  904. 17.09 04:06:16 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  905. 17.09 04:06:16 INFO  [PasswordLoginContainer] Start LOGIN
  906. 17.09 04:06:16 INFO  [TechProcessImpl] userLogin ru.crystals.pos.user.UserEntity[id=null]
  907. 17.09 04:06:16 INFO  [TechProcessImpl] userLogout
  908. 17.09 04:06:16 INFO  [CommonLogger] getFactory().getTechProcess().isShiftOpen() = true
  909. 17.09 04:06:16 INFO  [CommonLogger] getFactory().getTechProcess().checkUserRight(Right.SHOW_MAIN_MODE)) = true
  910. 17.09 04:06:16 INFO  [PasswordLoginContainer] Finish LOGIN
  911. 17.09 04:06:16 INFO  [SpeedLog] TechProcess authenticating user time = 92 ms
  912. 17.09 04:06:16 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":3,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":198,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":0.0,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:16.183","offline":false}]}
  913. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  914. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] **********************
  915. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  916. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  917. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] **********************
  918. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract]
  919. 17.09 04:06:16 INFO  [Scale] BarcodeScannerImpl - barcode = 5029053534572
  920. 17.09 04:06:16 INFO  [TechProcessImpl] eventBarcodeScanner 5029053534572
  921. 17.09 04:06:16 INFO  [CheckContainer] Barcode 5029053534572 has been received by visualisation
  922. 17.09 04:06:16 INFO  [TechProcessImpl] TP searchProduct 5029053534572
  923. 17.09 04:06:16 INFO  [CatalogService] getGoodsByBarCode barcode = 5029053534572
  924. 17.09 04:06:16 INFO  [CatalogService] get product by barcode '5029053534572' result: ProductPieceEntity[name=Безалкогольный энергетический напиток НеПиво, item=5029053534572]
  925. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5029053534572 time = 2 ms
  926. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5029053534572 time = 2 ms
  927. 17.09 04:06:16 INFO  [SpeedLog] getProductRestrictions  time = 1 ms
  928. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5029053534572 time = 3 ms
  929. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5029053534572 time = 3 ms
  930. 17.09 04:06:16 INFO  [SpeedLog] searchProduct time  time = 3 ms
  931. 17.09 04:06:16 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":4,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":198,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":0.0,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:16.294","offline":false}]}
  932. 17.09 04:06:16 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,027 sec; average speed = 0,047 sec; position test num = 815.0; prooduct item 5029053534572; <27>
  933. 17.09 04:06:16 INFO  [CommonLogger] busy = false
  934. 17.09 04:06:16 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":198,"pos":1,"barcode":"5029053534572","item":"5029053534572","name":"Безалкогольный энергетический ","price":300.5,"quant":1.0,"sum":300.5,"sumAll":300.5,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:16.294","offline":false}]}
  935. 17.09 04:06:16 INFO  [Scale] BarcodeScannerImpl - barcode = 5084101000003
  936. 17.09 04:06:16 INFO  [TechProcessImpl] eventBarcodeScanner 5084101000003
  937. 17.09 04:06:16 INFO  [CheckContainer] Barcode 5084101000003 has been received by visualisation
  938. 17.09 04:06:16 INFO  [CheckContainer] All conditions are checked. Current position will be added
  939. 17.09 04:06:16 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 5029053534572; type: ProductPieceEntity; count: 1000; sum: 30050; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  940. 17.09 04:06:16 INFO  [SpeedLog] TP addPosition time = 13 ms
  941. 17.09 04:06:16 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,024 sec; average speed = 0,031 sec; position test num = 277; <24>
  942. 17.09 04:06:16 INFO  [CheckContainer] visualization will start searching product
  943. 17.09 04:06:16 INFO  [TechProcessImpl] TP searchProduct 5084101000003
  944. 17.09 04:06:16 INFO  [CatalogService] getGoodsByBarCode barcode = 5084101000003
  945. 17.09 04:06:16 INFO  [CatalogService] get product by barcode '5084101000003' result: ProductSpiritsEntity[name=Пивас тёмное слабоватое (Великобритания), item=84101]
  946. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5084101000003 time = 2 ms
  947. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5084101000003 time = 2 ms
  948. 17.09 04:06:16 INFO  [SpeedLog] getProductRestrictions  time = 2 ms
  949. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5084101000003 time = 4 ms
  950. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5084101000003 time = 4 ms
  951. 17.09 04:06:16 INFO  [SpeedLog] searchProduct time  time = 4 ms
  952. 17.09 04:06:16 INFO  [Scale] BarcodeScannerImpl - barcode = 5084101000003
  953. 17.09 04:06:16 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,032 sec; average speed = 0,047 sec; position test num = 816.0; prooduct item 84101; <32>
  954. 17.09 04:06:16 INFO  [CommonLogger] busy = false
  955. 17.09 04:06:16 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":198,"pos":2,"barcode":"5084101000003","item":"84101","name":"Пивас тёмное слабоватое (Велик","price":534.36,"quant":1.0,"sum":534.36,"sumAll":834.86,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:16.395","offline":false}]}
  956. 17.09 04:06:16 INFO  [TechProcessImpl] eventBarcodeScanner 5084101000003
  957. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  958. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] **********************
  959. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] *Пивас тёмно 1 534.36*
  960. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] *Итого         834.86*
  961. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] **********************
  962. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract]
  963. 17.09 04:06:16 INFO  [CheckContainer] Barcode 5084101000003 has been received by visualisation
  964. 17.09 04:06:16 INFO  [CheckContainer] All conditions are checked. Current position will be added
  965. 17.09 04:06:16 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 84101; type: ProductSpiritsEntity; count: 1000; sum: 53436; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  966. 17.09 04:06:16 INFO  [SpeedLog] TP addPosition time = 31 ms
  967. 17.09 04:06:16 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,077 sec; average speed = 0,031 sec; position test num = 278; <77>
  968. 17.09 04:06:16 INFO  [CheckContainer] visualization will start searching product
  969. 17.09 04:06:16 INFO  [TechProcessImpl] TP searchProduct 5084101000003
  970. 17.09 04:06:16 INFO  [CatalogService] getGoodsByBarCode barcode = 5084101000003
  971. 17.09 04:06:16 INFO  [CatalogService] get product by barcode '5084101000003' result: ProductSpiritsEntity[name=Пивас тёмное слабоватое (Великобритания), item=84101]
  972. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5084101000003 time = 2 ms
  973. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5084101000003 time = 2 ms
  974. 17.09 04:06:16 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  975. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5084101000003 time = 2 ms
  976. 17.09 04:06:16 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5084101000003 time = 2 ms
  977. 17.09 04:06:16 INFO  [SpeedLog] searchProduct time  time = 2 ms
  978. 17.09 04:06:16 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,057 sec; average speed = 0,047 sec; position test num = 817.0; prooduct item 84101; <57>
  979. 17.09 04:06:16 INFO  [CommonLogger] busy = false
  980. 17.09 04:06:16 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=32, command=kbdSubtotal]
  981. 17.09 04:06:16 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 84101; type: ProductSpiritsEntity; count: 1000; sum: 53436; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  982. 17.09 04:06:16 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":1688,"cash":60,"mode":67,"tabNumber":"2","cashier":"Кассиров К.К.","purchase":198,"pos":3,"barcode":"5084101000003","item":"84101","name":"Пивас тёмное слабоватое (Велик","price":534.36,"quant":1.0,"sum":534.36,"sumAll":1369.22,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"17.09.2018 04:06:16.827","offline":false}]}
  983. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  984. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] **********************
  985. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] *Пивас тёмно 1 534.36*
  986. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] *Итого        1369.22*
  987. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract] **********************
  988. 17.09 04:06:16 INFO  [TextCustomerDisplayPluginAbstract]
  989. 17.09 04:06:17 INFO  [SpeedLog] TP addPosition time = 411 ms
  990. 17.09 04:06:17 INFO  [CommonLogger] busy = true
  991. 17.09 04:06:17 TRACE [TechProcessImpl] Start warn divide alco
  992. 17.09 04:06:17 TRACE [TechProcessImpl] End warn devide alco
  993. 17.09 04:06:17 INFO  [TechProcessImpl] goToDiscounts
  994. 17.09 04:06:18 DEBUG [TechProcessImpl] Server online mode
  995. 17.09 04:06:18 INFO  [TransferManager] Nothing yet not processed on server to resend
  996. 17.09 04:06:19 INFO  [LoyalBridgeServiceImpl] --------------- begin discount calculation ---------------
  997. 17.09 04:06:19 INFO  [LoyalProductFinder] Time finding items (2) = 2 ms
  998. 17.09 04:06:19 INFO  [LoyalProductsConverter] Time searching loyal goods for 2 productItems = 2 ms
  999. 17.09 04:06:19 INFO  [LoyalCalculatorConverter] Time converting 2 positions = 0 ms
  1000. 17.09 04:06:20 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 4
  1001. 17.09 04:06:20 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1002.     Id: MQ==
  1003.     Date: 2018-09-17 02:04:47.719
  1004. 17.09 04:06:20 TRACE [MLServiceImpl] entering getServices()
  1005. 17.09 04:06:20 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1006. 17.09 04:06:20 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1007. 17.09 04:06:20 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1008. 17.09 04:06:20 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1009. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1010.     <request>
  1011.         <ClientTransactionId>1</ClientTransactionId>
  1012.         <Organization>Victoria</Organization>
  1013.         <BusinessUnit>1688</BusinessUnit>
  1014.         <POS>60</POS>
  1015.         <CardNumber>99990002</CardNumber>
  1016.         <DateTime>2018-09-17T04:06:20.171+03:00</DateTime>
  1017.     </request>
  1018. </DissociatingCard>
  1019.  
  1020. 17.09 04:06:21 ERROR [LoyaltyRestrictionsServiceImpl] checkRestrictions: failed
  1021. org.springframework.web.client.HttpServerErrorException: 500 Server Error
  1022.     at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:94)
  1023.     at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:616)
  1024.     at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:572)
  1025.     at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:532)
  1026.     at org.springframework.web.client.RestTemplate.postForObject(RestTemplate.java:332)
  1027.     at ru.crystals.pos.loyalty.LoyaltyRestrictionsServiceImpl.checkRestrictions(LoyaltyRestrictionsServiceImpl.java:172)
  1028.     at ru.crystals.loyal.providers.ClassicSetLoyProvider.process(ClassicSetLoyProvider.java:88)
  1029.     at ru.crystals.loyal.providers.LoyProvidersRegistryImpl.process(LoyProvidersRegistryImpl.java:135)
  1030.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.calcDiscounts(LoyalServiceImpl.java:748)
  1031.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doLoyalty(LoyalServiceImpl.java:667)
  1032.     at ru.crystals.pos.loyal.cash.service.LoyalServiceImpl.doDiscount(LoyalServiceImpl.java:766)
  1033.     at ru.crystals.pos.loyal.bridge.service.LoyalBridgeServiceImpl.doDiscount(LoyalBridgeServiceImpl.java:372)
  1034.     at ru.crystals.pos.techprocess.TechProcessImpl.applyDiscountsAndGetResult(TechProcessImpl.java:3550)
  1035.     at ru.crystals.pos.techprocess.TechProcessImpl.subtotalScenary(TechProcessImpl.java:3113)
  1036.     at ru.crystals.pos.visualization.check.CheckContainer.startSubtotalScenary(CheckContainer.java:1477)
  1037.     at ru.crystals.pos.visualization.check.CheckContainer.subtotalProcessPurchaseState(CheckContainer.java:1448)
  1038.     at ru.crystals.pos.visualization.check.CheckContainer.subtotal(CheckContainer.java:1345)
  1039.     at ru.crystals.pos.visualization.components.MainWindow.subTotal(MainWindow.java:833)
  1040.     at ru.crystals.pos.visualization.Factory.eventFunctionKey(Factory.java:538)
  1041.     at ru.crystals.pos.techprocess.TechProcessImpl.eventFunctionKey(TechProcessImpl.java:4167)
  1042.     at ru.crystals.pos.CashEventSource.sentOldKey(CashEventSource.java:165)
  1043.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:138)
  1044.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  1045.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  1046.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$1(InternalCashPoolExecutorImpl.java:120)
  1047.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1048.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  1049.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  1050.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  1051.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1052.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1053.     at java.lang.Thread.run(Thread.java:745)
  1054. 17.09 04:06:21 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  1055. 17.09 04:06:21 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  1056. 17.09 04:06:21 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1057. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  1058.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1059.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1060.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1061.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1062.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1063.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1064.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1065.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1066.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  1067.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  1068.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  1069.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  1070.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1071.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1072.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1073.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1074.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1075.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1076.     at java.lang.Thread.run(Thread.java:745)
  1077. 17.09 04:06:21 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1078. 17.09 04:06:21 WARN  [AdvertisingActionUtils] superfluous [1] CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2346;guid=60699;name=Спасибо от Сбербанка;parentGuid=null;masterActions=[];mode=UNCONDITIONAL;worksAnyTime=true;useRestrictions=true;priority=1160.0]) one!
  1079. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing CFT-backed bonus discount action [AdvertisingActionEntity:[id=2026;guid=-1506222621;name=РА_Спасибо_до50р;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1320.0]] from further processing 'cause it has no chance to trigger anyway!
  1080. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=1989;guid=422993713;name=РА_ЦФТ_исключение10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1050.0]] from further processing 'cause it has no chance to trigger anyway!
  1081. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=2474;guid=422993744;name=РА_ЦФТ_исключение20;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1060.0]] from further processing 'cause it has no chance to trigger anyway!
  1082. 17.09 04:06:21 WARN  [AdvertisingActionUtils] superfluous [2] BONUS_CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=3189;guid=1935033882;name=РА_ЦФТ_без_ограничений;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1070.0]) one!
  1083. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=2926;guid=1270000641;name=SET10BONUSES: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=10.0]] from further processing 'cause it has no chance to trigger anyway!
  1084. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3759;guid=58449;name=SR-2252_AdvAct_WriteoffBonuses;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1020.0]] from further processing 'cause it has no chance to trigger anyway!
  1085. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3318;guid=61192;name=SR-2185: Автоматическое списание бонусов SET10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1170.0]] from further processing 'cause it has no chance to trigger anyway!
  1086. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=1895;guid=-833406141;name=SR-1177: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=2000.0]] from further processing 'cause it has no chance to trigger anyway!
  1087. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=3704;guid=59275;name=Бонусы Лента списание;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1080.0]] from further processing 'cause it has no chance to trigger anyway!
  1088. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=2334;guid=-6683376;name=Lenta_cobranding_decrement-CR-1019;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1505.0]] from further processing 'cause it has no chance to trigger anyway!
  1089. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_LOYMAX-backed bonus discount action [AdvertisingActionEntity:[id=2046;guid=61281;name=Списание бонусных баллов LOYMAX;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1180.0]] from further processing 'cause it has no chance to trigger anyway!
  1090. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=2926;guid=1270000641;name=SET10BONUSES: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=10.0]] from further processing 'cause it has no chance to trigger anyway!
  1091. 17.09 04:06:21 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1092. 17.09 04:06:21 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1093. 17.09 04:06:21 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1094. 17.09 04:06:21 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1095. 17.09 04:06:21 ERROR [MLServiceImpl] Could not send pending operation (id: 111013; date: 2018-09-17 02:04:47.719)
  1096. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1097.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  1098.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  1099.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  1100.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1101.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1102.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1103.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1104.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1105.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1106.     at java.lang.Thread.run(Thread.java:745)
  1107. 17.09 04:06:21 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1108.     Id: MQ==
  1109.     Date: 2018-09-17 02:02:53.316
  1110. 17.09 04:06:21 TRACE [MLServiceImpl] entering getServices()
  1111. 17.09 04:06:21 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1112. 17.09 04:06:21 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1113. 17.09 04:06:21 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1114. 17.09 04:06:21 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1115. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1116.     <request>
  1117.         <ClientTransactionId>1</ClientTransactionId>
  1118.         <Organization>Victoria</Organization>
  1119.         <BusinessUnit>1688</BusinessUnit>
  1120.         <POS>60</POS>
  1121.         <CardNumber>99990002</CardNumber>
  1122.         <DateTime>2018-09-17T04:06:21.238+03:00</DateTime>
  1123.     </request>
  1124. </DissociatingCard>
  1125.  
  1126. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3759;guid=58449;name=SR-2252_AdvAct_WriteoffBonuses;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1020.0]] from further processing 'cause it has no chance to trigger anyway!
  1127. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=1989;guid=422993713;name=РА_ЦФТ_исключение10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1050.0]] from further processing 'cause it has no chance to trigger anyway!
  1128. 17.09 04:06:21 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1129. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  1130.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1131.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1132.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1133.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1134.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1135.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1136.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1137.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1138.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  1139.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  1140.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  1141.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  1142.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1143.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1144.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1145.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1146.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1147.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1148.     at java.lang.Thread.run(Thread.java:745)
  1149. 17.09 04:06:21 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1150. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_CFT-backed bonus discount action [AdvertisingActionEntity:[id=2474;guid=422993744;name=РА_ЦФТ_исключение20;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1060.0]] from further processing 'cause it has no chance to trigger anyway!
  1151. 17.09 04:06:21 WARN  [AdvertisingActionUtils] superfluous [0] BONUS_CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=3189;guid=1935033882;name=РА_ЦФТ_без_ограничений;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1070.0]) one!
  1152. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=3704;guid=59275;name=Бонусы Лента списание;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1080.0]] from further processing 'cause it has no chance to trigger anyway!
  1153. 17.09 04:06:21 ERROR [MLServiceImpl] Could not send pending operation (id: 111011; date: 2018-09-17 02:02:53.316)
  1154. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1155.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  1156.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  1157.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  1158.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1159.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1160.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1161.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1162.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1163.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1164.     at java.lang.Thread.run(Thread.java:745)
  1165. 17.09 04:06:21 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1166.     Id: MQ==
  1167.     Date: 2018-09-17 02:03:31.243
  1168. 17.09 04:06:21 TRACE [MLServiceImpl] entering getServices()
  1169. 17.09 04:06:21 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1170. 17.09 04:06:21 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1171. 17.09 04:06:21 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1172. 17.09 04:06:21 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1173. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1174.     <request>
  1175.         <ClientTransactionId>1</ClientTransactionId>
  1176.         <Organization>Victoria</Organization>
  1177.         <BusinessUnit>1688</BusinessUnit>
  1178.         <POS>60</POS>
  1179.         <CardNumber>99990001</CardNumber>
  1180.         <DateTime>2018-09-17T04:06:21.274+03:00</DateTime>
  1181.     </request>
  1182. </DissociatingCard>
  1183.  
  1184. 17.09 04:06:21 WARN  [AdvertisingActionUtils] superfluous [0] CFT-backed bonus actions were detected! Removing all of them from the further processing save for the first (arbitrary! namely: AdvertisingActionEntity:[id=2346;guid=60699;name=Спасибо от Сбербанка;parentGuid=null;masterActions=[];mode=UNCONDITIONAL;worksAnyTime=true;useRestrictions=true;priority=1160.0]) one!
  1185. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=3318;guid=61192;name=SR-2185: Автоматическое списание бонусов SET10;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1170.0]] from further processing 'cause it has no chance to trigger anyway!
  1186. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_LOYMAX-backed bonus discount action [AdvertisingActionEntity:[id=2046;guid=61281;name=Списание бонусных баллов LOYMAX;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1180.0]] from further processing 'cause it has no chance to trigger anyway!
  1187. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing CFT-backed bonus discount action [AdvertisingActionEntity:[id=2026;guid=-1506222621;name=РА_Спасибо_до50р;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1320.0]] from further processing 'cause it has no chance to trigger anyway!
  1188. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_INFORMIX-backed bonus discount action [AdvertisingActionEntity:[id=2334;guid=-6683376;name=Lenta_cobranding_decrement-CR-1019;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=true;priority=1505.0]] from further processing 'cause it has no chance to trigger anyway!
  1189. 17.09 04:06:21 WARN  [AdvertisingActionUtils] removing BONUS_SR10-backed bonus discount action [AdvertisingActionEntity:[id=1895;guid=-833406141;name=SR-1177: Списание бонусных баллов с карты;parentGuid=null;masterActions=[];mode=AUTOMATIC;worksAnyTime=true;useRestrictions=false;priority=2000.0]] from further processing 'cause it has no chance to trigger anyway!
  1190. 17.09 04:06:21 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  1191. 17.09 04:06:21 TRACE [LoyPluginEmulator] entering doDiscount(Receipt). The argument is: ru.crystals.api.commons.ReceiptPurchaseWrapper@16d44d0
  1192. 17.09 04:06:21 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  1193. 17.09 04:06:21 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  1194. 17.09 04:06:21 TRACE [LoyPluginEmulator] leaving readProperties(IntegrationProperties, Logger). The result is: LoyPluginEmulatorProperties{primaryCalcUrl=http://127.0.0.1:10065/loy-plugin-processing/emulator/process, secondaryCalcUrl=null, feedbackUrl=http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback, connectionTimeout=1000, readTimeout=1000, quiet=false, cardProcessingId='null'}; it took 2 [ms]
  1195. 17.09 04:06:21 TRACE [LoyPluginEmulator] entering makeCalcCalls(List, EmulatorReceipt). The arguments are: urls: [http://127.0.0.1:10065/loy-plugin-processing/emulator/process], emulatorReceipt: emul-receipt [card: null; positions: [emul-pos [no: 1; marking: "5029053534572"; qnty: 1000; sum: 30050; min-sum: 0; discountable: true], emul-pos [no: 2; marking: "84101"; qnty: 2000; sum: 106872; min-sum: 0; discountable: true]]]
  1196. 17.09 04:06:21 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  1197. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: java.lang.NullPointerException Please see the server log to find more detail regarding exact cause of the failure.
  1198.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  1199.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  1200.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  1201.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  1202.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  1203.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  1204.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  1205.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  1206.     at com.sun.proxy.$Proxy225.dissociatingCard(Unknown Source)
  1207.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1470)
  1208.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  1209.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  1210.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1211.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1212.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1213.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1214.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1215.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1216.     at java.lang.Thread.run(Thread.java:745)
  1217. 17.09 04:06:21 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  1218. 17.09 04:06:21 ERROR [MLServiceImpl] Could not send pending operation (id: 111012; date: 2018-09-17 02:03:31.243)
  1219. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  1220.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1486)
  1221.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:102)
  1222.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1543)
  1223.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  1224.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  1225.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  1226.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  1227.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  1228.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  1229.     at java.lang.Thread.run(Thread.java:745)
  1230. 17.09 04:06:21 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  1231.     Id: MQ==
  1232.     Date: 2018-09-17 02:02:17.864
  1233. 17.09 04:06:21 TRACE [MLServiceImpl] entering getServices()
  1234. 17.09 04:06:21 TRACE [MLServiceImpl] getting services (IN MEMORY)
  1235. 17.09 04:06:21 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  1236. 17.09 04:06:21 TRACE [MLServiceImpl] Going to send DissociatingCard:
  1237. 17.09 04:06:21 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1238. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  1239.     <request>
  1240.         <ClientTransactionId>1</ClientTransactionId>
  1241.         <Organization>Victoria</Organization>
  1242.         <BusinessUnit>1688</BusinessUnit>
  1243.         <POS>60</POS>
  1244.         <CardNumber>99990002</CardNumber>
  1245.         <DateTime>2018-09-17T04:06:21.343+03:00</DateTime>
  1246.     </request>
  1247. </DissociatingCard>
  1248.  
  1249. 17.09 04:06:21 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  1250. 17.09 04:06:21 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  1251. 17.09 04:06:21 TRACE [LoyPluginEmulator] leaving makeCalcCalls(List, EmulatorReceipt). The result is: emul-loy-result [discounts: []; limit: null; taken-into-account: null]; it took 506 [ms]
  1252. 17.09 04:06:21 TRACE [LoyPluginEmulator] leaving doDiscount(Receipt). The result is: loy-result [discounts: []; bonus-limits: {}]; it took 508 [ms]
  1253. 17.09 04:06:21 INFO  [LoyalServiceImpl] Discount calculation (Purchase #198; Positions: 2
  1254. 17.09 04:06:21 INFO  [AdvResultPersistenceManager] createLoyTx: either the receipt [Purchase:[number=198;dateCreate=2018-09-17 04:06:16.330;operationType=true;checkSum=136922;discount=0]] does not have discounts, or has corresponding loy-tx in the DB already
  1255. 17.09 04:06:21 WARN  [LoyalServiceImpl] extractNonDiscountRelatedFields: the argument is NULL! Null will be returned!
  1256. 17.09 04:06:21 INFO  [AdvResultPersistenceManager] createLoyTx: either the receipt [Purchase:[number=198;dateCreate=2018-09-17 04:06:16.330;operationType=true;checkSum=136922;discount=0]] does not have discounts, or has corresponding loy-tx in the DB already
  1257. 17.09 04:06:21 INFO  [LoyalBridgeServiceImpl] Total time of discount calculation = 1886 ms
  1258. 17.09 04:06:21 INFO  [LoyalBridgeServiceImpl] ---------------- end discount calculation ----------------
  1259. 17.09 04:06:21 INFO  [FiscalPrinter] resetException()
  1260. 17.09 04:06:21 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1261. 17.09 04:06:21 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1262. 17.09 04:06:21 INFO  [TextCustomerDisplayPluginAbstract] *Скидка          0.00*
  1263. 17.09 04:06:21 INFO  [TextCustomerDisplayPluginAbstract] *Итого        1369.22*
  1264. 17.09 04:06:21 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1265. 17.09 04:06:21 INFO  [TextCustomerDisplayPluginAbstract]
  1266. 17.09 04:06:21 INFO  [SpeedLog] TechProcess discounts processing on cheque with 2 positions [sale] time = 4449 ms
  1267. 17.09 04:06:21 INFO  [CommonLogger] value = 0
  1268. 17.09 04:06:21 TRACE [TechProcessImpl] Start warn divide amount
  1269. 17.09 04:06:21 INFO  [TechProcessImpl] goToPayments
  1270. 17.09 04:06:21 INFO  [CheckContainer] startPayments() surcharge = 136922
  1271. 17.09 04:06:21 ERROR [TechProcessImpl] TP error: Adding new events is blocked
  1272. 17.09 04:06:21 INFO  [CheckContainer] isPaymentComplete = false
  1273. 17.09 04:06:21 INFO  [CheckContainer] prevState = ADD_POSITION
  1274. 17.09 04:06:21 INFO  [CheckContainer] paid = 0
  1275. 17.09 04:06:21 INFO  [CheckContainer] surcharge = 136922
  1276. 17.09 04:06:21 INFO  [CheckContainer] getPaymentFiscalizeError = NONE
  1277. 17.09 04:06:21 INFO  [CheckContainer] Current payment container is ru.crystals.pos.visualization.payments.cash.CashPaymentContainer
  1278. 17.09 04:06:21 INFO  [CommonLogger] busy = false
  1279. 17.09 04:06:21 INFO  [SpeedLog] (SUBTOTAL) time = 4,606;
  1280. 17.09 04:06:21 INFO  [CommonLogger] busy = false
  1281. 17.09 04:06:22 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1282. 17.09 04:06:22 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1283. 17.09 04:06:22 INFO  [TextCustomerDisplayPluginAbstract] *Скидка          0.00*
  1284. 17.09 04:06:22 INFO  [TextCustomerDisplayPluginAbstract] *Итого        1369.22*
  1285. 17.09 04:06:22 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1286. 17.09 04:06:22 INFO  [TextCustomerDisplayPluginAbstract]
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!