API tools faq
paste
Advertisement
fedorm

Untitled

fedorm
Aug 8th, 2019
299
0
Never
Add comment
Not a member of Pastebin yet? Sign Up, it unlocks many cool features!
XML 216.65 KB | None | 0 0
raw download clone embed print report
  1. 08.08 00:40:02.452 INFO  [CommonLogger] Cleaning done.
  2. 08.08 00:40:02.453 INFO  [LoyProvidersRegistryImpl] Found 5 stale feedbacks for SetApiLoyaltyPlugin. Submit to executor
  3. 08.08 00:40:02.453 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = loymax
  4. 08.08 00:40:02.454 INFO  [LoyProvidersRegistryImpl] There is no stale feedback for loymax
  5. 08.08 00:40:02.454 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = sm
  6. 08.08 00:40:02.456 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  7. 08.08 00:40:02.457 INFO  [LoyProvidersRegistryImpl] There is no stale feedback for sm
  8. 08.08 00:40:02.457 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = kopilka
  9. 08.08 00:40:02.458 INFO  [LoyProvidersRegistryImpl] There is no stale feedback for kopilka
  10. 08.08 00:40:02.458 INFO  [LoyProvidersRegistryImpl] Search for stale feedbacks provider = smch
  11. 08.08 00:40:02.624 INFO  [LoyProvidersRegistryImpl] There is no stale feedback for smch
  12. 08.08 00:40:02.611 TRACE [MLServiceImpl] entering isEnabled()
  13. 08.08 00:40:02.762 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  14. 08.08 00:40:03.334 ERROR [TransactionHandler]
  15. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-9 - Connection is not available, request timed out after 36321ms.
  16.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  17.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  18.     at com.sun.proxy.$Proxy211.getNextUnsendedMessages(Unknown Source)
  19.     at ru.crystals.pos.prismabridge.PrismaBridgeImpl$NetworkSenderTask.run(PrismaBridgeImpl.java:370)
  20.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  21.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  22.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  23.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  24.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  25.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  26.     at java.lang.Thread.run(Thread.java:745)
  27. Caused by: java.sql.SQLTransientConnectionException: HikariPool-9 - Connection is not available, request timed out after 36321ms.
  28.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  29.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  30.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  31.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  32.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  33.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  34.     ... 10 more
  35. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  36.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  37.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  38.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  39.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  40.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  41.     ... 14 more
  42. 08.08 00:40:03.335 TRACE [MLServiceImpl] Entering commitDiscounts (LoyExtProviderFeedback). The argument is LoyExtProviderFeedback{id=5570, payload=<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  43. <ProcessRequest xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  44.     <request>
  45.         <ChequeRequest>
  46.             <Card>
  47.                 <CardNumber>2612341234</CardNumber>
  48.             </Card>
  49.             <DateTime>2019-08-08T00:29:24.809+03:00</DateTime>
  50.             <Organization>Victoria</Organization>
  51.             <BusinessUnit>7171</BusinessUnit>
  52.             <POS>61</POS>
  53.             <Number>1565213363902</Number>
  54.             <OperationType>Return</OperationType>
  55.             <Summ>1300.00</Summ>
  56.             <Discount>0.000</Discount>
  57.             <SummDiscounted>1300.00</SummDiscounted>
  58.             <Item>
  59.                 <PositionNumber>1</PositionNumber>
  60.                 <Article>33020021</Article>
  61.                 <ArticleName>Детский товар</ArticleName>
  62.                 <Price>1300.00</Price>
  63.                 <Quantity>1.000</Quantity>
  64.                 <Summ>1300.00</Summ>
  65.                 <Discount>0.000</Discount>
  66.                 <SummDiscounted>1300.00</SummDiscounted>
  67.             </Item>
  68.         </ChequeRequest>
  69.     </request>
  70. </ProcessRequest>
  71. }
  72. 08.08 00:40:03.335 ERROR [TransactionHandler]
  73. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155842ms.
  74.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  75.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  76.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  77.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.isSendDocsToESBEnabled(TransferManager.java:155)
  78.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$000(TransferManager.java:55)
  79.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:102)
  80.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  81.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  82.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  83.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  84.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  85.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  86.     at java.lang.Thread.run(Thread.java:745)
  87. Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155842ms.
  88.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  89.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  90.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  91.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  92.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  93.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  94.     ... 12 more
  95. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  96.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  97.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  98.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  99.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  100.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  101.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  102.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  103.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  104.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  105.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  106.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  107.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.isTransportAllowed(FilesChecker.java:179)
  108.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.run(FilesChecker.java:88)
  109.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  110.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  111.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  112.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  113.     ... 3 more
  114. 08.08 00:40:04.537 ERROR [JDBCMapperImpl] Cannot rollback transaction
  115. java.lang.NullPointerException
  116.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  117.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  118.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  119.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  120.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.isSendDocsToESBEnabled(TransferManager.java:155)
  121.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$000(TransferManager.java:55)
  122.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$RepeatSender.run(TransferManager.java:102)
  123.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  124.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  125.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  126.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  127.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  128.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  129.     at java.lang.Thread.run(Thread.java:745)
  130. 08.08 00:40:03.335 ERROR [TransactionHandler]
  131. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 126542ms.
  132.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  133.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  134.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  135.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.isSendDocsToESBEnabled(TransferManager.java:155)
  136.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$000(TransferManager.java:55)
  137.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$ResendRequester.run(TransferManager.java:120)
  138.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  139.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  140.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  141.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  142.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  143.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  144.     at java.lang.Thread.run(Thread.java:745)
  145. Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 126542ms.
  146.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  147.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  148.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  149.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  150.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  151.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  152.     ... 12 more
  153. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  154.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  155.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  156.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  157.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  158.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  159.     ... 16 more
  160. 08.08 00:40:03.335 ERROR [TransactionHandler]
  161. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155843ms.
  162.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  163.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  164.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  165.     at ru.crystals.pos.esb.KafkaProducerBeanImpl.isEnabled(KafkaProducerBeanImpl.java:65)
  166.     at ru.crystals.pos.check.service.transport.TransferManager.sendByESBEnabled(TransferManager.java:1043)
  167.     at ru.crystals.pos.check.service.transport.DocumentSender.sendObject(DocumentSender.java:309)
  168.     at ru.crystals.pos.check.service.transport.TransferManager$CashStatusSender.run(TransferManager.java:338)
  169.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  170.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  171.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  172.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  173.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  174.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  175.     at java.lang.Thread.run(Thread.java:745)
  176. Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155843ms.
  177.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  178.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  179.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  180.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  181.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  182.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  183.     ... 13 more
  184. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  185.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  186.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  187.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  188.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  189.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  190.     ... 17 more
  191. 08.08 00:40:03.335 ERROR [TransactionHandler]
  192. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155703ms.
  193.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  194.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  195.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  196.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.isTransportAllowed(FilesChecker.java:179)
  197.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.run(FilesChecker.java:88)
  198.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  199.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  200.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  201.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  202.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  203.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  204.     at java.lang.Thread.run(Thread.java:745)
  205. Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155703ms.
  206.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  207.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  208.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  209.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  210.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  211.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  212.     ... 11 more
  213. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  214.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  215.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  216.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  217.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  218.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  219.     ... 15 more
  220. 08.08 00:40:04.669 ERROR [JDBCMapperImpl] Cannot rollback transaction
  221. java.lang.NullPointerException
  222.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  223.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  224.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  225.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  226.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.isTransportAllowed(FilesChecker.java:179)
  227.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.run(FilesChecker.java:88)
  228.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  229.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  230.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  231.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  232.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  233.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  234.     at java.lang.Thread.run(Thread.java:745)
  235. 08.08 00:40:03.335 ERROR [TransactionHandler]
  236. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-8 - Connection is not available, request timed out after 104941ms.
  237.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  238.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  239.     at com.sun.proxy.$Proxy202.isLimitsReset(Unknown Source)
  240.     at ru.crystals.pos.catalog.limits.ProductLimitsService.processNewLimits(ProductLimitsService.java:328)
  241.     at ru.crystals.pos.catalog.limits.ProductLimitsService.run(ProductLimitsService.java:118)
  242.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  243.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  244.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  245.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  246.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  247.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  248.     at java.lang.Thread.run(Thread.java:745)
  249. Caused by: java.sql.SQLTransientConnectionException: HikariPool-8 - Connection is not available, request timed out after 104941ms.
  250.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  251.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  252.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  253.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  254.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  255.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  256.     ... 11 more
  257. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  258.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  259.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  260.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  261.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  262.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  263.     ... 15 more
  264. 08.08 00:40:04.542 ERROR [JDBCMapperImpl] Cannot rollback transaction
  265. java.lang.NullPointerException
  266.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  267.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  268.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  269.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  270.     at ru.crystals.pos.esb.KafkaProducerBeanImpl.isEnabled(KafkaProducerBeanImpl.java:65)
  271.     at ru.crystals.pos.check.service.transport.TransferManager.sendByESBEnabled(TransferManager.java:1043)
  272.     at ru.crystals.pos.check.service.transport.DocumentSender.sendObject(DocumentSender.java:309)
  273.     at ru.crystals.pos.check.service.transport.TransferManager$CashStatusSender.run(TransferManager.java:338)
  274.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  275.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  276.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  277.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  278.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  279.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  280.     at java.lang.Thread.run(Thread.java:745)
  281. 08.08 00:40:04.540 ERROR [JDBCMapperImpl] Cannot rollback transaction
  282. java.lang.NullPointerException
  283.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  284.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  285.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  286.     at com.sun.proxy.$Proxy211.getNextUnsendedMessages(Unknown Source)
  287.     at ru.crystals.pos.prismabridge.PrismaBridgeImpl$NetworkSenderTask.run(PrismaBridgeImpl.java:370)
  288.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  289.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  290.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  291.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  292.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  293.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  294.     at java.lang.Thread.run(Thread.java:745)
  295. 08.08 00:40:04.538 ERROR [JDBCMapperImpl] Cannot rollback transaction
  296. java.lang.NullPointerException
  297.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  298.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  299.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  300.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  301.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.isSendDocsToESBEnabled(TransferManager.java:155)
  302.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager.access$000(TransferManager.java:55)
  303.     at ru.crystals.pos.loyal.cash.transport.discountresults.TransferManager$ResendRequester.run(TransferManager.java:120)
  304.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  305.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  306.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  307.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  308.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  309.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  310.     at java.lang.Thread.run(Thread.java:745)
  311. 08.08 00:40:04.542 INFO  [MLServiceImpl] Number of pending operations (DISSOCIATING_CARD_MANZANA): 3
  312. 08.08 00:40:04.743 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  313.     Id: MQ==
  314.     Date: 2019-08-07 22:14:16.537
  315. 08.08 00:40:04.743 TRACE [MLServiceImpl] entering getServices()
  316. 08.08 00:40:04.744 TRACE [MLServiceImpl] getting services (IN MEMORY)
  317. 08.08 00:40:04.744 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  318. 08.08 00:40:04.744 ERROR [JDBCMapperImpl] Cannot rollback transaction
  319. java.lang.NullPointerException
  320.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.closeConnection(JDBCMapperImpl.java:129)
  321.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.rollbackTransaction(JDBCMapperImpl.java:210)
  322.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:30)
  323.     at com.sun.proxy.$Proxy202.isLimitsReset(Unknown Source)
  324.     at ru.crystals.pos.catalog.limits.ProductLimitsService.processNewLimits(ProductLimitsService.java:328)
  325.     at ru.crystals.pos.catalog.limits.ProductLimitsService.run(ProductLimitsService.java:118)
  326.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  327.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  328.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  329.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  330.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  331.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  332.     at java.lang.Thread.run(Thread.java:745)
  333. 08.08 00:40:04.797 TRACE [MLServiceImpl] Going to send DissociatingCard:
  334. 08.08 00:40:05.016 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  335. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  336.     <request>
  337.         <ClientTransactionId>1</ClientTransactionId>
  338.         <Organization>Victoria</Organization>
  339.         <BusinessUnit>7171</BusinessUnit>
  340.         <POS>61</POS>
  341.         <CardNumber>99990002</CardNumber>
  342.         <DateTime>2019-08-08T00:40:04.797+03:00</DateTime>
  343.     </request>
  344. </DissociatingCard>
  345.  
  346. 08.08 00:40:04.740 ERROR [FilesChecker] failed to get ESB ON/OFF status
  347. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155703ms.
  348.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  349.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  350.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  351.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.isTransportAllowed(FilesChecker.java:179)
  352.     at ru.crystals.pos.catalog.service.filestransport.FilesChecker.run(FilesChecker.java:88)
  353.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  354.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  355.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  356.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  357.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  358.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  359.     at java.lang.Thread.run(Thread.java:745)
  360. Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155703ms.
  361.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  362.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  363.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  364.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  365.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  366.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  367.     ... 11 more
  368. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  369.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  370.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  371.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  372.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  373.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  374.     ... 15 more
  375. 08.08 00:40:04.745 INFO  [RegistryImpl] Subscription URLs of module PRODUCTS:
  376.     HTTP : http://172.29.17.171:8090
  377. 08.08 00:40:05.303 INFO  [RegistryImpl] Try register SubscriptionURL - PRODUCTS : HTTP:http://172.29.17.171:8090
  378. 08.08 00:40:05.303 INFO  [HttpClient] Set url - http://172.29.17.171:8090/SetXRMI/TransportServlet
  379. 08.08 00:40:09.036 ERROR [ProductLimitsService]
  380. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-8 - Connection is not available, request timed out after 104941ms.
  381.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  382.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  383.     at com.sun.proxy.$Proxy202.isLimitsReset(Unknown Source)
  384.     at ru.crystals.pos.catalog.limits.ProductLimitsService.processNewLimits(ProductLimitsService.java:328)
  385.     at ru.crystals.pos.catalog.limits.ProductLimitsService.run(ProductLimitsService.java:118)
  386.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  387.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  388.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  389.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  390.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  391.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  392.     at java.lang.Thread.run(Thread.java:745)
  393. Caused by: java.sql.SQLTransientConnectionException: HikariPool-8 - Connection is not available, request timed out after 104941ms.
  394.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  395.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  396.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  397.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  398.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  399.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  400.     ... 11 more
  401. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  402.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  403.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  404.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  405.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  406.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  407.     ... 15 more
  408. 08.08 00:40:04.742 WARN  [TransferManager] java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155843ms.
  409. java.lang.RuntimeException: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155843ms.
  410.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:180)
  411.     at ru.crystals.pos.datasource.jdbc.TransactionHandler.invoke(TransactionHandler.java:25)
  412.     at com.sun.proxy.$Proxy158.getProperty(Unknown Source)
  413.     at ru.crystals.pos.esb.KafkaProducerBeanImpl.isEnabled(KafkaProducerBeanImpl.java:65)
  414.     at ru.crystals.pos.check.service.transport.TransferManager.sendByESBEnabled(TransferManager.java:1043)
  415.     at ru.crystals.pos.check.service.transport.DocumentSender.sendObject(DocumentSender.java:309)
  416.     at ru.crystals.pos.check.service.transport.TransferManager$CashStatusSender.run(TransferManager.java:338)
  417.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  418.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  419.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  420.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  421.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  422.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  423.     at java.lang.Thread.run(Thread.java:745)
  424. Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 155843ms.
  425.     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
  426.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
  427.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
  428.     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  429.     at ru.crystals.pos.datasource.jdbc.JDBCMapperDSImpl.getConnection(JDBCMapperDSImpl.java:50)
  430.     at ru.crystals.pos.datasource.jdbc.JDBCMapperImpl.startTransaction(JDBCMapperImpl.java:174)
  431.     ... 13 more
  432. Caused by: org.postgresql.util.PSQLException: Соединение уже было закрыто
  433.     at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:767)
  434.     at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1537)
  435.     at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
  436.     at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
  437.     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
  438.     ... 17 more
  439. 08.08 00:40:07.949 INFO  [TransferManager] OD found 0 documents to register
  440. 08.08 00:40:08.936 TRACE [LoyPluginEmulator] entering onSendFeedback(LoyProviderFeedback). The argument is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  441. 08.08 00:40:09.190 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  442. 08.08 00:40:09.198 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  443. 08.08 00:40:09.198 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, cardProcessingId='null'}; it took 8 [ms]
  444. 08.08 00:40:09.198 TRACE [LoyPluginEmulator] entering makeFeedbackCall(URL, String, int, int). The arguments are: url [http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback], feedback [feedback from loyalty plugin emulator], connTimeout [1000], readTimeout [1000]
  445. 08.08 00:40:09.199 INFO  [DocumentSender] OD found 0 transactions to register
  446. 08.08 00:40:09.208 INFO  [DocumentSender] response message = Created
  447. 08.08 00:40:09.208 INFO  [TransferManager] Send document status : 16882 > WAIT_ACKNOWLEDGEMENT            file name : 61/Document_20190808004009_204_7171_61.ser
  448. 08.08 00:40:09.215 INFO  [CheckService] SetSentToServerStatus : 16882 > WAIT_ACKNOWLEDGEMENT file name : 61/Document_20190808004009_204_7171_61.ser
  449. 08.08 00:40:09.248 INFO  [DocumentSender] document 61/Document_20190808004009_204_7171_61.ser has been registered
  450. 08.08 00:40:09.249 INFO  [TransferManager] Send document status : 16882 > SENT            file name : 61/Document_20190808004009_204_7171_61.ser
  451. 08.08 00:40:09.253 INFO  [CheckService] SetSentToServerStatus : 16882 > SENT file name : 61/Document_20190808004009_204_7171_61.ser
  452. 08.08 00:40:09.610 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  453. 08.08 00:40:09.676 TRACE [LoyPluginEmulator] leaving makeFeedbackCall(URL, String, int, int). It took 478 [ms]
  454. 08.08 00:40:09.676 TRACE [LoyPluginEmulator] leaving onSendFeedback(LoyProviderFeedback). The result is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  455. 08.08 00:40:09.896 INFO  [DocumentSender] OD found 0 payment transactions
  456. 08.08 00:40:10.516 TRACE [LoyPluginEmulator] entering onSendFeedback(LoyProviderFeedback). The argument is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  457. 08.08 00:40:10.516 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  458. 08.08 00:40:10.516 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  459. 08.08 00:40:10.520 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, cardProcessingId='null'}; it took 3 [ms]
  460. 08.08 00:40:10.520 TRACE [LoyPluginEmulator] entering makeFeedbackCall(URL, String, int, int). The arguments are: url [http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback], feedback [feedback from loyalty plugin emulator], connTimeout [1000], readTimeout [1000]
  461. 08.08 00:40:10.529 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  462. 08.08 00:40:10.531 TRACE [LoyPluginEmulator] leaving makeFeedbackCall(URL, String, int, int). It took 11 [ms]
  463. 08.08 00:40:10.532 TRACE [LoyPluginEmulator] leaving onSendFeedback(LoyProviderFeedback). The result is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  464. 08.08 00:40:10.576 TRACE [LoyPluginEmulator] entering onSendFeedback(LoyProviderFeedback). The argument is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  465. 08.08 00:40:10.576 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  466. 08.08 00:40:10.576 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  467. 08.08 00:40:10.577 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, cardProcessingId='null'}; it took 1 [ms]
  468. 08.08 00:40:10.577 TRACE [LoyPluginEmulator] entering makeFeedbackCall(URL, String, int, int). The arguments are: url [http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback], feedback [feedback from loyalty plugin emulator], connTimeout [1000], readTimeout [1000]
  469. 08.08 00:40:10.637 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  470. 08.08 00:40:10.672 TRACE [LoyPluginEmulator] leaving makeFeedbackCall(URL, String, int, int). It took 95 [ms]
  471. 08.08 00:40:10.672 TRACE [LoyPluginEmulator] leaving onSendFeedback(LoyProviderFeedback). The result is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  472. 08.08 00:40:10.725 TRACE [LoyPluginEmulator] entering onSendFeedback(LoyProviderFeedback). The argument is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  473. 08.08 00:40:10.725 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  474. 08.08 00:40:10.725 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  475. 08.08 00:40:10.725 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, cardProcessingId='null'}; it took 0 [ms]
  476. 08.08 00:40:10.725 TRACE [LoyPluginEmulator] entering makeFeedbackCall(URL, String, int, int). The arguments are: url [http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback], feedback [feedback from loyalty plugin emulator], connTimeout [1000], readTimeout [1000]
  477. 08.08 00:40:10.737 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  478. 08.08 00:40:10.739 TRACE [LoyPluginEmulator] leaving makeFeedbackCall(URL, String, int, int). It took 14 [ms]
  479. 08.08 00:40:10.739 TRACE [LoyPluginEmulator] leaving onSendFeedback(LoyProviderFeedback). The result is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  480. 08.08 00:40:10.770 TRACE [LoyPluginEmulator] entering onSendFeedback(LoyProviderFeedback). The argument is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  481. 08.08 00:40:10.770 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  482. 08.08 00:40:10.770 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  483. 08.08 00:40:10.770 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, cardProcessingId='null'}; it took 0 [ms]
  484. 08.08 00:40:10.770 TRACE [LoyPluginEmulator] entering makeFeedbackCall(URL, String, int, int). The arguments are: url [http://127.0.0.1:10065/loy-plugin-processing/emulator/feedback], feedback [feedback from loyalty plugin emulator], connTimeout [1000], readTimeout [1000]
  485. 08.08 00:40:10.776 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  486. 08.08 00:40:10.778 TRACE [LoyPluginEmulator] leaving makeFeedbackCall(URL, String, int, int). It took 8 [ms]
  487. 08.08 00:40:10.778 TRACE [LoyPluginEmulator] leaving onSendFeedback(LoyProviderFeedback). The result is: LoyProviderFeedback{attemptsCount=0, savingStrategy=REPLACE, actionOnReceiptCancellation=REMOVE}
  488. 08.08 00:40:10.873 ERROR [KeyboardImpl]
  489. ScanCodes queue:
  490. [51, 52, 53, 54]
  491. ru.crystals.pos.keyboard.exception.KeyboardException: False scanner event
  492.     at ru.crystals.pos.keyboard.plugin.KeyboardPluginImpl$KeyboardListener.run(KeyboardPluginImpl.java:228)
  493.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  494.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  495.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  496.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  497.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  498.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  499.     at java.lang.Thread.run(Thread.java:745)
  500. 08.08 00:40:12.223 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  501. 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.
  502.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  503.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  504.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  505.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  506.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  507.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  508.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  509.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  510.     at com.sun.proxy.$Proxy244.dissociatingCard(Unknown Source)
  511.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  512.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  513.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  514.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  515.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  516.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  517.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  518.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  519.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  520.     at java.lang.Thread.run(Thread.java:745)
  521. 08.08 00:40:12.225 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  522. 08.08 00:40:12.226 ERROR [MLServiceImpl] Could not send pending operation (id: 552; date: 2019-08-07 22:14:16.537)
  523. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  524.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  525.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  526.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  527.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  528.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  529.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  530.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  531.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  532.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  533.     at java.lang.Thread.run(Thread.java:745)
  534. 08.08 00:40:12.227 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  535.     Id: MQ==
  536.     Date: 2019-08-07 22:13:30.595
  537. 08.08 00:40:12.227 TRACE [MLServiceImpl] entering getServices()
  538. 08.08 00:40:12.227 TRACE [MLServiceImpl] getting services (IN MEMORY)
  539. 08.08 00:40:12.227 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  540. 08.08 00:40:12.227 TRACE [MLServiceImpl] Going to send DissociatingCard:
  541. 08.08 00:40:12.227 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  542. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  543.     <request>
  544.         <ClientTransactionId>1</ClientTransactionId>
  545.         <Organization>Victoria</Organization>
  546.         <BusinessUnit>7171</BusinessUnit>
  547.         <POS>61</POS>
  548.         <CardNumber>99990002</CardNumber>
  549.         <DateTime>2019-08-08T00:40:12.227+03:00</DateTime>
  550.     </request>
  551. </DissociatingCard>
  552.  
  553. 08.08 00:40:12.314 INFO  [FiscalPrinter] resetException()
  554. 08.08 00:40:12.320 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  555. 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.
  556.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  557.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  558.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  559.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  560.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  561.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  562.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  563.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  564.     at com.sun.proxy.$Proxy244.dissociatingCard(Unknown Source)
  565.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  566.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  567.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  568.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  569.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  570.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  571.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  572.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  573.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  574.     at java.lang.Thread.run(Thread.java:745)
  575. 08.08 00:40:12.320 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  576. 08.08 00:40:12.338 TRACE [MLServiceImpl] entering getServices()
  577. 08.08 00:40:12.338 TRACE [MLServiceImpl] getting services (IN MEMORY)
  578. 08.08 00:40:12.338 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  579. 08.08 00:40:12.338 ERROR [MLServiceImpl] Could not send pending operation (id: 550; date: 2019-08-07 22:13:30.595)
  580. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  581.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  582.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  583.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  584.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  585.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  586.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  587.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  588.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  589.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  590.     at java.lang.Thread.run(Thread.java:745)
  591. 08.08 00:40:12.339 INFO  [MLServiceImpl] Try to cancel pending operation (DISSOCIATING_CARD_MANZANA):
  592.     Id: MQ==
  593.     Date: 2019-08-07 22:13:43.746
  594. 08.08 00:40:12.339 TRACE [MLServiceImpl] entering getServices()
  595. 08.08 00:40:12.339 TRACE [MLServiceImpl] getting services (IN MEMORY)
  596. 08.08 00:40:12.339 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  597. 08.08 00:40:12.339 TRACE [MLServiceImpl] Going to send DissociatingCard:
  598. 08.08 00:40:12.340 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.DissociatingCard is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  599. <DissociatingCard xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  600.     <request>
  601.         <ClientTransactionId>1</ClientTransactionId>
  602.         <Organization>Victoria</Organization>
  603.         <BusinessUnit>7171</BusinessUnit>
  604.         <POS>61</POS>
  605.         <CardNumber>99990005</CardNumber>
  606.         <DateTime>2019-08-08T00:40:12.339+03:00</DateTime>
  607.     </request>
  608. </DissociatingCard>
  609.  
  610. 08.08 00:40:12.558 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  611. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: Incorrect response! Check test method! Please see the server log to find more detail regarding exact cause of the failure.
  612.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  613.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  614.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  615.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  616.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  617.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  618.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  619.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  620.     at com.sun.proxy.$Proxy244.processRequest(Unknown Source)
  621.     at ru.crystals.pos.ml.MLServiceImpl.sendRequest(MLServiceImpl.java:992)
  622.     at ru.crystals.pos.ml.MLServiceImpl.commitDiscounts(MLServiceImpl.java:1095)
  623.     at ru.crystals.pos.ml.MLServiceImpl.commitDiscounts(MLServiceImpl.java:1073)
  624.     at ru.crystals.pos.loyal.ml.ManzanaLoyProvider.sendFeedback(ManzanaLoyProvider.java:142)
  625.     at ru.crystals.loyal.providers.LoyProvider.sendFeedback(LoyProvider.java:157)
  626.     at ru.crystals.loyal.providers.SendFeedbackTask.doSendFeedback(SendFeedbackTask.java:86)
  627.     at ru.crystals.loyal.providers.SendFeedbackTask.run(SendFeedbackTask.java:53)
  628.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  629.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  630.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  631.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  632.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  633.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  634.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  635.     at java.lang.Thread.run(Thread.java:745)
  636. 08.08 00:40:12.559 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  637. 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.
  638.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  639.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  640.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  641.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  642.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  643.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  644.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  645.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  646.     at com.sun.proxy.$Proxy244.dissociatingCard(Unknown Source)
  647.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1469)
  648.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  649.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  650.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  651.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  652.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  653.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  654.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  655.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  656.     at java.lang.Thread.run(Thread.java:745)
  657. 08.08 00:40:12.562 ERROR [MLServiceImpl] leaving unbind(String): failed to connect to any of the servers [1] in spite of spending {}
  658. 08.08 00:40:12.562 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.ProcessRequestResponse is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  659. <ProcessRequestResponse xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd"/>
  660.  
  661. 08.08 00:40:12.564 ERROR [MLServiceImpl] leaving calcDiscount(Purchase): failed to connect to any of the servers [{}]
  662. 08.08 00:40:12.579 ERROR [MLServiceImpl] Could not send pending operation (id: 551; date: 2019-08-07 22:13:43.746)
  663. ru.crystals.pos.ml.exception.MLConnectionException: Все сервера ML POS не доступны
  664.     at ru.crystals.pos.ml.MLServiceImpl.dissociatingCard(MLServiceImpl.java:1485)
  665.     at ru.crystals.pos.ml.MLServiceImpl.access$200(MLServiceImpl.java:100)
  666.     at ru.crystals.pos.ml.MLServiceImpl$PendingDissociatingCardOperation.run(MLServiceImpl.java:1542)
  667.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  668.     at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
  669.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
  670.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
  671.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  672.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  673.     at java.lang.Thread.run(Thread.java:745)
  674. 08.08 00:40:12.662 TRACE [MLServiceImpl] entering isEnabled()
  675. 08.08 00:40:12.662 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  676. 08.08 00:40:12.662 TRACE [MLServiceImpl] Entering commitDiscounts (LoyExtProviderFeedback). The argument is LoyExtProviderFeedback{id=5577, payload=<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  677. <ProcessRequest xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  678.     <request>
  679.         <ChequeRequest>
  680.             <Card>
  681.                 <CardNumber>2612341234</CardNumber>
  682.             </Card>
  683.             <DateTime>2019-08-08T00:30:31.585+03:00</DateTime>
  684.             <Organization>Victoria</Organization>
  685.             <BusinessUnit>7171</BusinessUnit>
  686.             <POS>61</POS>
  687.             <Number>1565213430632</Number>
  688.             <OperationType>Return</OperationType>
  689.             <Summ>1300.00</Summ>
  690.             <Discount>0.000</Discount>
  691.             <SummDiscounted>1300.00</SummDiscounted>
  692.             <Item>
  693.                 <PositionNumber>1</PositionNumber>
  694.                 <Article>33020021</Article>
  695.                 <ArticleName>Детский товар</ArticleName>
  696.                 <Price>1300.00</Price>
  697.                 <Quantity>1.000</Quantity>
  698.                 <Summ>1300.00</Summ>
  699.                 <Discount>0.000</Discount>
  700.                 <SummDiscounted>1300.00</SummDiscounted>
  701.             </Item>
  702.         </ChequeRequest>
  703.     </request>
  704. </ProcessRequest>
  705. }
  706. 08.08 00:40:12.667 TRACE [MLServiceImpl] entering getServices()
  707. 08.08 00:40:12.667 TRACE [MLServiceImpl] getting services (IN MEMORY)
  708. 08.08 00:40:12.667 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  709. 08.08 00:40:12.771 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  710. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: Incorrect response! Check test method! Please see the server log to find more detail regarding exact cause of the failure.
  711.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  712.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  713.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  714.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  715.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  716.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  717.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  718.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  719.     at com.sun.proxy.$Proxy244.processRequest(Unknown Source)
  720.     at ru.crystals.pos.ml.MLServiceImpl.sendRequest(MLServiceImpl.java:992)
  721.     at ru.crystals.pos.ml.MLServiceImpl.commitDiscounts(MLServiceImpl.java:1095)
  722.     at ru.crystals.pos.ml.MLServiceImpl.commitDiscounts(MLServiceImpl.java:1073)
  723.     at ru.crystals.pos.loyal.ml.ManzanaLoyProvider.sendFeedback(ManzanaLoyProvider.java:142)
  724.     at ru.crystals.loyal.providers.LoyProvider.sendFeedback(LoyProvider.java:157)
  725.     at ru.crystals.loyal.providers.SendFeedbackTask.doSendFeedback(SendFeedbackTask.java:86)
  726.     at ru.crystals.loyal.providers.SendFeedbackTask.run(SendFeedbackTask.java:53)
  727.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  728.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  729.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  730.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  731.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  732.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  733.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  734.     at java.lang.Thread.run(Thread.java:745)
  735. 08.08 00:40:12.772 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.ProcessRequestResponse is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  736. <ProcessRequestResponse xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd"/>
  737.  
  738. 08.08 00:40:12.772 ERROR [MLServiceImpl] leaving calcDiscount(Purchase): failed to connect to any of the servers [{}]
  739. 08.08 00:40:12.774 TRACE [MLServiceImpl] entering isEnabled()
  740. 08.08 00:40:12.774 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  741. 08.08 00:40:12.774 TRACE [MLServiceImpl] Entering commitDiscounts (LoyExtProviderFeedback). The argument is LoyExtProviderFeedback{id=5580, payload=<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  742. <ProcessRequest xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd">
  743.     <request>
  744.         <ChequeRequest>
  745.             <Card>
  746.                 <CardNumber>2612341234</CardNumber>
  747.             </Card>
  748.             <DateTime>2019-08-08T00:30:48.121+03:00</DateTime>
  749.             <Organization>Victoria</Organization>
  750.             <BusinessUnit>7171</BusinessUnit>
  751.             <POS>61</POS>
  752.             <Number>1565213447629</Number>
  753.             <OperationType>Return</OperationType>
  754.             <Summ>1300.00</Summ>
  755.             <Discount>0.000</Discount>
  756.             <SummDiscounted>1300.00</SummDiscounted>
  757.             <Item>
  758.                 <PositionNumber>1</PositionNumber>
  759.                 <Article>33020021</Article>
  760.                 <ArticleName>Детский товар</ArticleName>
  761.                 <Price>1300.00</Price>
  762.                 <Quantity>1.000</Quantity>
  763.                 <Summ>1300.00</Summ>
  764.                 <Discount>0.000</Discount>
  765.                 <SummDiscounted>1300.00</SummDiscounted>
  766.             </Item>
  767.         </ChequeRequest>
  768.     </request>
  769. </ProcessRequest>
  770. }
  771. 08.08 00:40:12.778 TRACE [MLServiceImpl] entering getServices()
  772. 08.08 00:40:12.778 TRACE [MLServiceImpl] getting services (IN MEMORY)
  773. 08.08 00:40:12.778 TRACE [MLServiceImpl] leaving getServices(). The result size is: 1
  774. 08.08 00:40:12.943 WARN  [MLServiceImpl] failed to connect to a ML POS web-service
  775. com.sun.xml.internal.ws.fault.ServerSOAPFaultException: Client received SOAP Fault from server: Incorrect response! Check test method! Please see the server log to find more detail regarding exact cause of the failure.
  776.     at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
  777.     at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:116)
  778.     at com.sun.xml.internal.ws.client.sei.StubHandler.readResponse(StubHandler.java:238)
  779.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:189)
  780.     at com.sun.xml.internal.ws.db.DatabindingImpl.deserializeResponse(DatabindingImpl.java:276)
  781.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:104)
  782.     at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:77)
  783.     at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:147)
  784.     at com.sun.proxy.$Proxy244.processRequest(Unknown Source)
  785.     at ru.crystals.pos.ml.MLServiceImpl.sendRequest(MLServiceImpl.java:992)
  786.     at ru.crystals.pos.ml.MLServiceImpl.commitDiscounts(MLServiceImpl.java:1095)
  787.     at ru.crystals.pos.ml.MLServiceImpl.commitDiscounts(MLServiceImpl.java:1073)
  788.     at ru.crystals.pos.loyal.ml.ManzanaLoyProvider.sendFeedback(ManzanaLoyProvider.java:142)
  789.     at ru.crystals.loyal.providers.LoyProvider.sendFeedback(LoyProvider.java:157)
  790.     at ru.crystals.loyal.providers.SendFeedbackTask.doSendFeedback(SendFeedbackTask.java:86)
  791.     at ru.crystals.loyal.providers.SendFeedbackTask.run(SendFeedbackTask.java:53)
  792.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  793.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  794.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  795.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  796.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  797.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  798.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  799.     at java.lang.Thread.run(Thread.java:745)
  800. 08.08 00:40:12.944 TRACE [MLServiceImpl] class ru.crystals.pos.ml.wsclient.ProcessRequestResponse is <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  801. <ProcessRequestResponse xmlns="http://loyalty.manzanagroup.ru/loyalty.xsd"/>
  802.  
  803. 08.08 00:40:12.944 ERROR [MLServiceImpl] leaving calcDiscount(Purchase): failed to connect to any of the servers [{}]
  804. 08.08 00:40:13.072 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=69, command=kbdMenu2]
  805. 08.08 00:40:13.275 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  806. 08.08 00:40:13.508 INFO  [FiscalPrinter] resetException()
  807. 08.08 00:40:13.678 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  808. 08.08 00:40:14.080 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  809. 08.08 00:40:14.283 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  810. 08.08 00:40:14.283 INFO  [CommonLogger] Menu command: Аннулирование (class ru.crystals.pos.visualization.menu.commands.CancelCheckCommand)
  811. 08.08 00:40:14.487 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=37, command=kbdLeft]
  812. 08.08 00:40:14.889 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  813. 08.08 00:40:14.891 INFO  [TechProcessShiftProxy] cancelCheck start
  814. 08.08 00:40:14.892 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
  815. 08.08 00:40:14.892 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
  816. 08.08 00:40:14.892 TRACE [ExternalProcessingsImpl] Discounts cancelled: no implementation of PlastekServices.
  817. 08.08 00:40:14.892 TRACE [ExternalProcessingsImpl] entering discountCancelledToSet5(PurchaseEntity)
  818. 08.08 00:40:14.892 TRACE [ExternalProcessingsImpl] leaving discountCancelledToSet5(PurchaseEntity): the SET5 loy processing is disabled
  819. 08.08 00:40:14.897 INFO  [WaitComponent] [WaitComponent] MainFrame enabled - false
  820. 08.08 00:40:15.010 WARN  [AeroflotBonusesLoyProvider] cancelDiscount failed: PurchaseEntity [id=16883, number=null, dateCreate=Thu Aug 08 00:36:34 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]. Service is not available
  821. 08.08 00:40:15.046 DEBUG [LoymaxUtils] Loymax request:
  822. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLRequest><Version>3.2</Version><CancelPurchases><CancelPurchaseRequest PurchaseID="71710611565213812915" OperationID="e4e7a76290ea498b933f42ba558eec67" OperationDate="2019-08-08T00:40:15.046+03:00" ElementID="1"/></CancelPurchases></XMLRequest>
  823.  
  824. 08.08 00:40:15.067 DEBUG [LoymaxUtils] Loymax response:
  825. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLResponse><ErrorCode>0</ErrorCode><CancelPurchases><CancelPurchaseResponse PurchaseID="71710611565213812915" OperationID="e4e7a76290ea498b933f42ba558eec67" OperationDate="2019-08-08T00:40:15.046+03:00" ErrorCode="0"/></CancelPurchases></XMLResponse>
  826.  
  827. 08.08 00:40:15.112 INFO  [TechProcessShiftProxy] cancelCheck PurchaseEntity [id=16883, number=null, dateCreate=Thu Aug 08 00:36:34 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  828. 08.08 00:40:15.133 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  829. 08.08 00:40:15.137 INFO  [TextCustomerDisplayPluginAbstract] **********************
  830. 08.08 00:40:15.137 INFO  [TextCustomerDisplayPluginAbstract] *Аннулирование чека  *
  831. 08.08 00:40:15.137 INFO  [TextCustomerDisplayPluginAbstract] *Сумма чека   7451.29*
  832. 08.08 00:40:15.137 INFO  [TextCustomerDisplayPluginAbstract] **********************
  833. 08.08 00:40:15.138 INFO  [TextCustomerDisplayPluginAbstract]
  834. 08.08 00:40:15.160 TRACE [ExternalProcessingsImpl] Purchase cancelled: no implementation of PlastekServices.
  835. 08.08 00:40:15.160 TRACE [MLServiceImpl] entering getMlCardNo(PurchaseEntity). The argument is: PurchaseEntity [id=16883, number=182, dateCreate=Thu Aug 08 00:36:34 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  836. 08.08 00:40:15.160 TRACE [MLServiceImpl] leaving getMlCardNo(PurchaseEntity). The result is: null
  837. 08.08 00:40:15.162 INFO  [FiscalPrinter] printCheck
  838. 08.08 00:40:15.162 INFO  [FiscalPrinter] Fiscal interrupt: null
  839. 08.08 00:40:15.164 INFO  [FiscalPrinter] Get document template /mnt/sda1/tce/storage/crystal-cash/modules/fiscalPrinter/templates/check-sale-annul.xml
  840. 08.08 00:40:15.164 INFO  [DocumentTemplate] =====logo=====
  841. 08.08 00:40:15.164 INFO  [DocumentTemplate] content: null
  842. 08.08 00:40:15.165 INFO  [DocumentTemplate] =====header=====
  843. 08.08 00:40:15.166 INFO  [DocumentTemplate]                    jr. name                   ||NORMAL
  844. 08.08 00:40:15.166 INFO  [DocumentTemplate]          199100, Spb, Savushkina, 112         ||NORMAL
  845. 08.08 00:40:15.166 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  846. 08.08 00:40:15.166 INFO  [DocumentTemplate] ЗВД.N:00000717161         ЭКЛЗ:    72afb605-7a||NORMAL
  847. 08.08 00:40:15.166 INFO  [DocumentTemplate] РЕГ.N:NFM.7171.61.0.156519ИНН:     7802781104 ||NORMAL
  848. 08.08 00:40:15.166 INFO  [DocumentTemplate] 01    Администраторов Адми     КАССА: 61 ОТД01||NORMAL
  849. 08.08 00:40:15.166 INFO  [DocumentTemplate]   ЧЕК НА ПРОДАЖУ N:182            ||NORMAL
  850. 08.08 00:40:15.166 INFO  [DocumentTemplate] =====text=====
  851. 08.08 00:40:15.166 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  852. 08.08 00:40:15.166 INFO  [DocumentTemplate] Кассовый чек (ПРИХОД)                         ||NORMAL
  853. 08.08 00:40:15.167 INFO  [DocumentTemplate]                *ПРОДАЖА ТОВАРА*               ||NORMAL
  854. 08.08 00:40:15.186 INFO  [DocumentTemplate] =====positionSectionWithGoodSets=====
  855. 08.08 00:40:15.187 INFO  [DocumentTemplate] ------------------------------------------||NORMAL
  856. 08.08 00:40:15.187 INFO  [DocumentTemplate] Напиток виноградный   471.83     *1    =471.83||SMALL
  857. 08.08 00:40:15.187 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  858. 08.08 00:40:15.187 INFO  [DocumentTemplate] Напиток томатный гу    86.25     *1     =86.25||SMALL
  859. 08.08 00:40:15.187 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  860. 08.08 00:40:15.189 INFO  [DocumentTemplate] Пряник апельсиновый   201.17     *1    =201.17||SMALL
  861. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  862. 08.08 00:40:15.189 INFO  [DocumentTemplate] Йогурт вишневый тер  1079.32     *1   =1079.32||SMALL
  863. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  864. 08.08 00:40:15.189 INFO  [DocumentTemplate] Напиток грушевый гу   347.55     *1    =347.55||SMALL
  865. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  866. 08.08 00:40:15.189 INFO  [DocumentTemplate] Шоколад вишневый го  1184.10     *1   =1184.10||SMALL
  867. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  868. 08.08 00:40:15.189 INFO  [DocumentTemplate] Лимонад банановый с  1089.98     *1   =1089.98||SMALL
  869. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  870. 08.08 00:40:15.189 INFO  [DocumentTemplate] Кефир виноградный а  1187.74     *1   =1187.74||SMALL
  871. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  872. 08.08 00:40:15.189 INFO  [DocumentTemplate] Йогурт яблочный соч  1199.18     *1   =1199.18||SMALL
  873. 08.08 00:40:15.189 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  874. 08.08 00:40:15.189 INFO  [DocumentTemplate] Напиток апельсиновы   604.17     *1    =604.17||SMALL
  875. 08.08 00:40:15.190 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  876. 08.08 00:40:15.190 INFO  [DocumentTemplate] ------------------------------------------||NORMAL
  877. 08.08 00:40:15.190 INFO  [DocumentTemplate] =====payment=====
  878. 08.08 00:40:15.190 INFO  [DocumentTemplate]          ИТОГО К ОПЛАТЕ         =7451.29      ||NORMAL
  879. 08.08 00:40:15.190 INFO  [DocumentTemplate] =====text=====
  880. 08.08 00:40:15.201 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  881. 08.08 00:40:15.201 INFO  [DocumentTemplate]  ||NORMAL
  882. 08.08 00:40:15.201 INFO  [DocumentTemplate]                *ПРОДАЖА ТОВАРА*               ||NORMAL
  883. 08.08 00:40:15.201 INFO  [DocumentTemplate]                                               ||NORMAL
  884. 08.08 00:40:15.201 INFO  [DocumentTemplate]              СПАСИБО ЗА ПОКУПКУ!              ||NORMAL
  885. 08.08 00:40:15.201 INFO  [DocumentTemplate]                                               ||NORMAL
  886. 08.08 00:40:15.201 INFO  [DocumentTemplate] =====text=====
  887. 08.08 00:40:15.201 INFO  [DocumentTemplate] =====fiscal=====
  888. 08.08 00:40:15.202 INFO  [DocumentTemplate]                                            ||NORMAL
  889. 08.08 00:40:15.202 INFO  [DocumentTemplate]        Вся информация на www.lenta.com     ||NORMAL
  890. 08.08 00:40:15.202 INFO  [DocumentTemplate]           и по тел. 8-800-700-4111         ||NORMAL
  891. 08.08 00:40:15.202 INFO  [DocumentTemplate]          звонок по России бесплатный       ||NORMAL
  892. 08.08 00:40:15.202 INFO  [DocumentTemplate] =====footer=====
  893. 08.08 00:40:15.202 INFO  [DocumentTemplate]             **********************            ||DOUBLEWIDTH
  894. 08.08 00:40:15.202 INFO  [DocumentTemplate]                ЧЕК АННУЛИРОВАН                ||DOUBLEWIDTH
  895. 08.08 00:40:15.202 INFO  [DocumentTemplate]             **********************            ||DOUBLEWIDTH
  896. 08.08 00:40:15.202 INFO  [DocumentTemplate] 08-08-2019 00:40       ||NORMAL
  897. 08.08 00:40:15.202 INFO  [DocumentTemplate] =====cut=====
  898. 08.08 00:40:15.202 INFO  [DocumentTemplate] content: null
  899. 08.08 00:40:15.391 INFO  [FiscalPrinter] getCountAnnul
  900. 08.08 00:40:15.391 INFO  [FiscalPrinter] CountAnnul = 48
  901. 08.08 00:40:15.391 INFO  [FiscalPrinter] getLastDocNum
  902. 08.08 00:40:15.608 INFO  [CheckService] cancelCheck: PurchaseEntity [id=16883, number=182, dateCreate=Thu Aug 08 00:36:34 MSK 2019, dateCommit=Thu Aug 08 00:40:15 MSK 2019, fiscalDocNum=48;1167, sentToServerStatus=NO_SENT]
  903. 08.08 00:40:15.762 WARN  [AeroflotBonusesLoyProvider] checkCanceled failed: PurchaseEntity [id=16883, number=182, dateCreate=Thu Aug 08 00:36:34 MSK 2019, dateCommit=Thu Aug 08 00:40:15 MSK 2019, fiscalDocNum=48;1167, sentToServerStatus=NO_SENT]. Service is not available
  904. 08.08 00:40:15.765 TRACE [SCService] entering isEnabled()
  905. 08.08 00:40:15.767 TRACE [SCService] leaving isEnabled(). the result is: true
  906. 08.08 00:40:15.767 TRACE [SCService] Check was canceled
  907. 08.08 00:40:15.767 TRACE [SCService] Stop send Personal Offer
  908. 08.08 00:40:15.768 INFO  [CommonLogger] value = 0
  909. 08.08 00:40:15.791 INFO  [TechProcessImpl] Select seller [null]
  910. 08.08 00:40:15.793 INFO  [SpeedLog] TechProcess cancelCheck time = 681 ms
  911. 08.08 00:40:15.797 INFO  [WaitComponent] [WaitComponent] MainFrame enabled - true
  912. 08.08 00:40:15.793 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":25,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":182,"pos":0,"barcode":"","item":"","name":"","price":0.0,"quant":0.0,"sum":0.0,"sumAll":7451.29,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:15.793","offline":false}]}
  913. 08.08 00:40:15.807 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  914. 08.08 00:40:15.807 INFO  [TextCustomerDisplayPluginAbstract] **********************
  915. 08.08 00:40:15.807 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  916. 08.08 00:40:15.808 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  917. 08.08 00:40:15.808 INFO  [TextCustomerDisplayPluginAbstract] **********************
  918. 08.08 00:40:15.808 INFO  [TextCustomerDisplayPluginAbstract]
  919. 08.08 00:40:15.810 INFO  [TechProcessImpl] Select seller [null]
  920. 08.08 00:40:15.851 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  921. 08.08 00:40:16.052 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=87, command=kbdMenu1]
  922. 08.08 00:40:16.141 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  923. 08.08 00:40:16.141 INFO  [TextCustomerDisplayPluginAbstract] **********************
  924. 08.08 00:40:16.141 INFO  [TextCustomerDisplayPluginAbstract] *Добро               *
  925. 08.08 00:40:16.141 INFO  [TextCustomerDisplayPluginAbstract] *пожаловать          *
  926. 08.08 00:40:16.141 INFO  [TextCustomerDisplayPluginAbstract] **********************
  927. 08.08 00:40:16.142 INFO  [TextCustomerDisplayPluginAbstract]
  928. 08.08 00:40:16.874 INFO  [CommonLogger] Starting cleaning. All log records older than 10 мая 2019 00:40:16 will be deleted.
  929. 08.08 00:40:16.876 INFO  [CommonLogger] Cleaning done.
  930. 08.08 00:40:17.794 INFO  [Scale] BarcodeScannerImpl - barcode = 8402800000006
  931. 08.08 00:40:17.798 INFO  [TechProcessImpl] eventBarcodeScanner 8402800000006
  932. 08.08 00:40:17.799 TRACE [MLServiceImpl] entering isEnabled()
  933. 08.08 00:40:17.799 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  934. 08.08 00:40:17.799 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "8402800000006"
  935. 08.08 00:40:17.799 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  936. 08.08 00:40:17.799 TRACE [SCService] entering isEnabled()
  937. 08.08 00:40:17.799 TRACE [SCService] leaving isEnabled(). the result is: true
  938. 08.08 00:40:17.799 TRACE [SCService] entering isSmChCoupon(String). The argument is: "8402800000006"
  939. 08.08 00:40:17.799 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  940. 08.08 00:40:17.799 TRACE [MLServiceImpl] entering isEnabled()
  941. 08.08 00:40:17.799 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  942. 08.08 00:40:17.799 TRACE [SCService] entering isEnabled()
  943. 08.08 00:40:17.799 TRACE [SCService] leaving isEnabled(). the result is: true
  944. 08.08 00:40:17.799 INFO  [CheckContainer] Barcode 8402800000006 has been received by visualisation
  945. 08.08 00:40:17.800 INFO  [TechProcessImpl] TP searchProduct 8402800000006
  946. 08.08 00:40:17.800 INFO  [CatalogService] getGoodsByBarCode barcode = 8402800000006
  947. 08.08 00:40:17.826 INFO  [CatalogService] get product by barcode '8402800000006' result: ProductPieceEntity[name=Шоколад малиновый пряный (Испания), item=02800]
  948. 08.08 00:40:17.826 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 8402800000006 time = 26 ms
  949. 08.08 00:40:17.826 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 8402800000006 time = 26 ms
  950. 08.08 00:40:17.826 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  951. 08.08 00:40:17.826 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 8402800000006 time = 26 ms
  952. 08.08 00:40:17.827 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 8402800000006 time = 27 ms
  953. 08.08 00:40:17.827 INFO  [SpeedLog] searchProduct time  time = 27 ms
  954. 08.08 00:40:17.838 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,011 sec; average speed = 0,034 sec; position test num = 1414.0; product item 02800; <11>
  955. 08.08 00:40:17.838 INFO  [CommonLogger] busy = false
  956. 08.08 00:40:17.839 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":4,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"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":"08.08.2019 00:40:17.838","offline":false}]}
  957. 08.08 00:40:17.855 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  958. 08.08 00:40:17.855 INFO  [TextCustomerDisplayPluginAbstract] **********************
  959. 08.08 00:40:17.855 INFO  [TextCustomerDisplayPluginAbstract] *Шоколад мал 1 262.27*
  960. 08.08 00:40:17.855 INFO  [TextCustomerDisplayPluginAbstract] *Итого         262.27*
  961. 08.08 00:40:17.855 INFO  [TextCustomerDisplayPluginAbstract] **********************
  962. 08.08 00:40:17.856 INFO  [TextCustomerDisplayPluginAbstract]
  963. 08.08 00:40:17.861 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":1,"barcode":"8402800000006","item":"02800","name":"Шоколад малиновый пряный (Испа","price":262.27,"quant":1.0,"sum":262.27,"sumAll":262.27,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:17.840","offline":false}]}
  964. 08.08 00:40:19.469 INFO  [Scale] BarcodeScannerImpl - barcode = 4600310000002
  965. 08.08 00:40:19.469 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  966. 08.08 00:40:19.488 INFO  [TechProcessImpl] eventBarcodeScanner 4600310000002
  967. 08.08 00:40:19.488 TRACE [MLServiceImpl] entering isEnabled()
  968. 08.08 00:40:19.488 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  969. 08.08 00:40:19.488 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "4600310000002"
  970. 08.08 00:40:19.488 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  971. 08.08 00:40:19.488 TRACE [SCService] entering isEnabled()
  972. 08.08 00:40:19.488 TRACE [SCService] leaving isEnabled(). the result is: true
  973. 08.08 00:40:19.489 TRACE [SCService] entering isSmChCoupon(String). The argument is: "4600310000002"
  974. 08.08 00:40:19.489 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  975. 08.08 00:40:19.489 TRACE [MLServiceImpl] entering isEnabled()
  976. 08.08 00:40:19.489 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  977. 08.08 00:40:19.489 TRACE [SCService] entering isEnabled()
  978. 08.08 00:40:19.489 TRACE [SCService] leaving isEnabled(). the result is: true
  979. 08.08 00:40:19.489 INFO  [CheckContainer] Barcode 4600310000002 has been received by visualisation
  980. 08.08 00:40:19.489 INFO  [CheckContainer] All conditions are checked. Current position will be added
  981. 08.08 00:40:19.490 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 02800; type: ProductPieceEntity; count: 1000; sum: 26227; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  982. 08.08 00:40:19.527 INFO  [SpeedLog] TP addPosition time = 37 ms
  983. 08.08 00:40:19.535 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,046 sec; average speed = 0,028 sec; position test num = 516; <46>
  984. 08.08 00:40:19.535 INFO  [CheckContainer] visualization will start searching product
  985. 08.08 00:40:19.535 INFO  [TechProcessImpl] TP searchProduct 4600310000002
  986. 08.08 00:40:19.536 INFO  [CatalogService] getGoodsByBarCode barcode = 4600310000002
  987. 08.08 00:40:19.536 INFO  [CatalogService] get product by barcode '4600310000002' result: ProductPieceEntity[name=Шоколад яблочный терпкий (Россия), item=00310]
  988. 08.08 00:40:19.536 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 4600310000002 time = 0 ms
  989. 08.08 00:40:19.538 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 4600310000002 time = 0 ms
  990. 08.08 00:40:19.538 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  991. 08.08 00:40:19.539 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 4600310000002 time = 3 ms
  992. 08.08 00:40:19.540 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 4600310000002 time = 4 ms
  993. 08.08 00:40:19.540 INFO  [SpeedLog] searchProduct time  time = 4 ms
  994. 08.08 00:40:19.557 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,015 sec; average speed = 0,034 sec; position test num = 1415.0; product item 00310; <15>
  995. 08.08 00:40:19.557 INFO  [CommonLogger] busy = false
  996. 08.08 00:40:19.558 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  997. 08.08 00:40:19.558 INFO  [TextCustomerDisplayPluginAbstract] **********************
  998. 08.08 00:40:19.558 INFO  [TextCustomerDisplayPluginAbstract] *Шоколад яблоч 1 2.92*
  999. 08.08 00:40:19.558 INFO  [TextCustomerDisplayPluginAbstract] *Итого         265.19*
  1000. 08.08 00:40:19.558 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1001. 08.08 00:40:19.558 INFO  [TextCustomerDisplayPluginAbstract]
  1002. 08.08 00:40:19.558 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":2,"barcode":"4600310000002","item":"00310","name":"Шоколад яблочный терпкий (Росс","price":2.92,"quant":1.0,"sum":2.92,"sumAll":265.19,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:19.557","offline":false}]}
  1003. 08.08 00:40:21.169 INFO  [Scale] BarcodeScannerImpl - barcode = 6908496000006
  1004. 08.08 00:40:21.169 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1005. 08.08 00:40:21.174 INFO  [TechProcessImpl] eventBarcodeScanner 6908496000006
  1006. 08.08 00:40:21.178 TRACE [MLServiceImpl] entering isEnabled()
  1007. 08.08 00:40:21.178 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1008. 08.08 00:40:21.178 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "6908496000006"
  1009. 08.08 00:40:21.178 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1010. 08.08 00:40:21.178 TRACE [SCService] entering isEnabled()
  1011. 08.08 00:40:21.178 TRACE [SCService] leaving isEnabled(). the result is: true
  1012. 08.08 00:40:21.178 TRACE [SCService] entering isSmChCoupon(String). The argument is: "6908496000006"
  1013. 08.08 00:40:21.179 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1014. 08.08 00:40:21.179 TRACE [MLServiceImpl] entering isEnabled()
  1015. 08.08 00:40:21.179 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1016. 08.08 00:40:21.179 TRACE [SCService] entering isEnabled()
  1017. 08.08 00:40:21.179 TRACE [SCService] leaving isEnabled(). the result is: true
  1018. 08.08 00:40:21.179 INFO  [CheckContainer] Barcode 6908496000006 has been received by visualisation
  1019. 08.08 00:40:21.180 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1020. 08.08 00:40:21.183 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 00310; type: ProductPieceEntity; count: 1000; sum: 292; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1021. 08.08 00:40:21.200 INFO  [SpeedLog] TP addPosition time = 17 ms
  1022. 08.08 00:40:21.201 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,022 sec; average speed = 0,028 sec; position test num = 517; <22>
  1023. 08.08 00:40:21.201 INFO  [CheckContainer] visualization will start searching product
  1024. 08.08 00:40:21.201 INFO  [TechProcessImpl] TP searchProduct 6908496000006
  1025. 08.08 00:40:21.202 INFO  [CatalogService] getGoodsByBarCode barcode = 6908496000006
  1026. 08.08 00:40:21.203 INFO  [CatalogService] get product by barcode '6908496000006' result: ProductPieceEntity[name=Напиток вишневый густой (Китай), item=08496]
  1027. 08.08 00:40:21.203 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 6908496000006 time = 1 ms
  1028. 08.08 00:40:21.203 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 6908496000006 time = 1 ms
  1029. 08.08 00:40:21.204 INFO  [SpeedLog] getProductRestrictions  time = 1 ms
  1030. 08.08 00:40:21.204 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 6908496000006 time = 2 ms
  1031. 08.08 00:40:21.204 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 6908496000006 time = 2 ms
  1032. 08.08 00:40:21.204 INFO  [SpeedLog] searchProduct time  time = 2 ms
  1033. 08.08 00:40:21.219 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,014 sec; average speed = 0,034 sec; position test num = 1416.0; product item 08496; <14>
  1034. 08.08 00:40:21.219 INFO  [CommonLogger] busy = false
  1035. 08.08 00:40:21.220 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":3,"barcode":"6908496000006","item":"08496","name":"Напиток вишневый густой (Китай","price":1131.45,"quant":1.0,"sum":1131.45,"sumAll":1396.64,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:21.219","offline":false}]}
  1036. 08.08 00:40:21.239 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1037. 08.08 00:40:21.239 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1038. 08.08 00:40:21.239 INFO  [TextCustomerDisplayPluginAbstract] *Напиток ви 1 1131.45*
  1039. 08.08 00:40:21.239 INFO  [TextCustomerDisplayPluginAbstract] *Итого        1396.64*
  1040. 08.08 00:40:21.239 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1041. 08.08 00:40:21.239 INFO  [TextCustomerDisplayPluginAbstract]
  1042. 08.08 00:40:22.862 INFO  [Scale] BarcodeScannerImpl - barcode = 5409246000006
  1043. 08.08 00:40:22.862 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1044. 08.08 00:40:22.870 INFO  [TechProcessImpl] eventBarcodeScanner 5409246000006
  1045. 08.08 00:40:22.871 TRACE [MLServiceImpl] entering isEnabled()
  1046. 08.08 00:40:22.871 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1047. 08.08 00:40:22.872 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "5409246000006"
  1048. 08.08 00:40:22.872 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1049. 08.08 00:40:22.872 TRACE [SCService] entering isEnabled()
  1050. 08.08 00:40:22.872 TRACE [SCService] leaving isEnabled(). the result is: true
  1051. 08.08 00:40:22.872 TRACE [SCService] entering isSmChCoupon(String). The argument is: "5409246000006"
  1052. 08.08 00:40:22.872 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1053. 08.08 00:40:22.872 TRACE [MLServiceImpl] entering isEnabled()
  1054. 08.08 00:40:22.872 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1055. 08.08 00:40:22.873 TRACE [SCService] entering isEnabled()
  1056. 08.08 00:40:22.873 TRACE [SCService] leaving isEnabled(). the result is: true
  1057. 08.08 00:40:22.873 INFO  [CheckContainer] Barcode 5409246000006 has been received by visualisation
  1058. 08.08 00:40:22.878 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1059. 08.08 00:40:22.879 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 08496; type: ProductPieceEntity; count: 1000; sum: 113145; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1060. 08.08 00:40:22.922 INFO  [SpeedLog] TP addPosition time = 43 ms
  1061. 08.08 00:40:22.927 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,054 sec; average speed = 0,028 sec; position test num = 518; <54>
  1062. 08.08 00:40:22.927 INFO  [CheckContainer] visualization will start searching product
  1063. 08.08 00:40:22.932 INFO  [TechProcessImpl] TP searchProduct 5409246000006
  1064. 08.08 00:40:22.932 INFO  [CatalogService] getGoodsByBarCode barcode = 5409246000006
  1065. 08.08 00:40:22.933 INFO  [CatalogService] get product by barcode '5409246000006' result: ProductPieceEntity[name=Напиток клубничный соленый (Бельгия), item=09246]
  1066. 08.08 00:40:22.933 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5409246000006 time = 1 ms
  1067. 08.08 00:40:22.933 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5409246000006 time = 1 ms
  1068. 08.08 00:40:22.934 INFO  [SpeedLog] getProductRestrictions  time = 1 ms
  1069. 08.08 00:40:22.934 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5409246000006 time = 2 ms
  1070. 08.08 00:40:22.934 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5409246000006 time = 2 ms
  1071. 08.08 00:40:22.934 INFO  [SpeedLog] searchProduct time  time = 2 ms
  1072. 08.08 00:40:22.950 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":4,"barcode":"5409246000006","item":"09246","name":"Напиток клубничный соленый (Бе","price":1254.69,"quant":1.0,"sum":1254.69,"sumAll":2651.33,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:22.949","offline":false}]}
  1073. 08.08 00:40:22.951 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,016 sec; average speed = 0,034 sec; position test num = 1417.0; product item 09246; <16>
  1074. 08.08 00:40:22.951 INFO  [CommonLogger] busy = false
  1075. 08.08 00:40:22.954 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1076. 08.08 00:40:22.954 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1077. 08.08 00:40:22.954 INFO  [TextCustomerDisplayPluginAbstract] *Напиток кл 1 1254.69*
  1078. 08.08 00:40:22.954 INFO  [TextCustomerDisplayPluginAbstract] *Итого        2651.33*
  1079. 08.08 00:40:22.954 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1080. 08.08 00:40:22.954 INFO  [TextCustomerDisplayPluginAbstract]
  1081. 08.08 00:40:24.632 INFO  [Scale] BarcodeScannerImpl - barcode = 8402021000007
  1082. 08.08 00:40:24.632 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1083. 08.08 00:40:24.641 INFO  [TechProcessImpl] eventBarcodeScanner 8402021000007
  1084. 08.08 00:40:24.642 TRACE [MLServiceImpl] entering isEnabled()
  1085. 08.08 00:40:24.642 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1086. 08.08 00:40:24.642 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "8402021000007"
  1087. 08.08 00:40:24.643 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1088. 08.08 00:40:24.643 TRACE [SCService] entering isEnabled()
  1089. 08.08 00:40:24.643 TRACE [SCService] leaving isEnabled(). the result is: true
  1090. 08.08 00:40:24.643 TRACE [SCService] entering isSmChCoupon(String). The argument is: "8402021000007"
  1091. 08.08 00:40:24.643 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1092. 08.08 00:40:24.643 TRACE [MLServiceImpl] entering isEnabled()
  1093. 08.08 00:40:24.643 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1094. 08.08 00:40:24.643 TRACE [SCService] entering isEnabled()
  1095. 08.08 00:40:24.643 TRACE [SCService] leaving isEnabled(). the result is: true
  1096. 08.08 00:40:24.643 INFO  [CheckContainer] Barcode 8402021000007 has been received by visualisation
  1097. 08.08 00:40:24.649 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1098. 08.08 00:40:24.649 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 09246; type: ProductPieceEntity; count: 1000; sum: 125469; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1099. 08.08 00:40:24.664 INFO  [SpeedLog] TP addPosition time = 15 ms
  1100. 08.08 00:40:24.665 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,022 sec; average speed = 0,028 sec; position test num = 519; <22>
  1101. 08.08 00:40:24.665 INFO  [CheckContainer] visualization will start searching product
  1102. 08.08 00:40:24.666 INFO  [TechProcessImpl] TP searchProduct 8402021000007
  1103. 08.08 00:40:24.666 INFO  [CatalogService] getGoodsByBarCode barcode = 8402021000007
  1104. 08.08 00:40:24.667 INFO  [CatalogService] get product by barcode '8402021000007' result: ProductPieceEntity[name=Кефир виноградный сладкий (Испания), item=02021]
  1105. 08.08 00:40:24.667 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 8402021000007 time = 1 ms
  1106. 08.08 00:40:24.667 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 8402021000007 time = 1 ms
  1107. 08.08 00:40:24.667 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  1108. 08.08 00:40:24.667 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 8402021000007 time = 1 ms
  1109. 08.08 00:40:24.667 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 8402021000007 time = 1 ms
  1110. 08.08 00:40:24.667 INFO  [SpeedLog] searchProduct time  time = 1 ms
  1111. 08.08 00:40:24.692 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,024 sec; average speed = 0,034 sec; position test num = 1418.0; product item 02021; <24>
  1112. 08.08 00:40:24.692 INFO  [CommonLogger] busy = false
  1113. 08.08 00:40:24.692 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":5,"barcode":"8402021000007","item":"02021","name":"Кефир виноградный сладкий (Исп","price":276.83,"quant":1.0,"sum":276.83,"sumAll":2928.16,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:24.692","offline":false}]}
  1114. 08.08 00:40:24.837 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1115. 08.08 00:40:24.837 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1116. 08.08 00:40:24.837 INFO  [TextCustomerDisplayPluginAbstract] *Кефир виног 1 276.83*
  1117. 08.08 00:40:24.837 INFO  [TextCustomerDisplayPluginAbstract] *Итого        2928.16*
  1118. 08.08 00:40:24.837 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1119. 08.08 00:40:24.837 INFO  [TextCustomerDisplayPluginAbstract]
  1120. 08.08 00:40:26.517 INFO  [Scale] BarcodeScannerImpl - barcode = 7201112000008
  1121. 08.08 00:40:26.517 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1122. 08.08 00:40:26.523 INFO  [TechProcessImpl] eventBarcodeScanner 7201112000008
  1123. 08.08 00:40:26.530 TRACE [MLServiceImpl] entering isEnabled()
  1124. 08.08 00:40:26.530 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1125. 08.08 00:40:26.530 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "7201112000008"
  1126. 08.08 00:40:26.531 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1127. 08.08 00:40:26.531 TRACE [SCService] entering isEnabled()
  1128. 08.08 00:40:26.531 TRACE [SCService] leaving isEnabled(). the result is: true
  1129. 08.08 00:40:26.531 TRACE [SCService] entering isSmChCoupon(String). The argument is: "7201112000008"
  1130. 08.08 00:40:26.535 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1131. 08.08 00:40:26.536 TRACE [MLServiceImpl] entering isEnabled()
  1132. 08.08 00:40:26.536 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1133. 08.08 00:40:26.536 TRACE [SCService] entering isEnabled()
  1134. 08.08 00:40:26.539 TRACE [SCService] leaving isEnabled(). the result is: true
  1135. 08.08 00:40:26.539 INFO  [CheckContainer] Barcode 7201112000008 has been received by visualisation
  1136. 08.08 00:40:26.541 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1137. 08.08 00:40:26.542 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 02021; type: ProductPieceEntity; count: 1000; sum: 27683; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1138. 08.08 00:40:26.561 INFO  [SpeedLog] TP addPosition time = 19 ms
  1139. 08.08 00:40:26.564 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,025 sec; average speed = 0,028 sec; position test num = 520; <25>
  1140. 08.08 00:40:26.564 INFO  [CheckContainer] visualization will start searching product
  1141. 08.08 00:40:26.565 INFO  [TechProcessImpl] TP searchProduct 7201112000008
  1142. 08.08 00:40:26.565 INFO  [CatalogService] getGoodsByBarCode barcode = 7201112000008
  1143. 08.08 00:40:26.566 INFO  [CatalogService] get product by barcode '7201112000008' result: ProductPieceEntity[name=Йогурт яблочный кислый (Израиль), item=01112]
  1144. 08.08 00:40:26.566 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 7201112000008 time = 0 ms
  1145. 08.08 00:40:26.566 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 7201112000008 time = 0 ms
  1146. 08.08 00:40:26.567 INFO  [SpeedLog] getProductRestrictions  time = 1 ms
  1147. 08.08 00:40:26.567 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 7201112000008 time = 1 ms
  1148. 08.08 00:40:26.567 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 7201112000008 time = 1 ms
  1149. 08.08 00:40:26.567 INFO  [SpeedLog] searchProduct time  time = 2 ms
  1150. 08.08 00:40:26.579 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":6,"barcode":"7201112000008","item":"01112","name":"Йогурт яблочный кислый (Израил","price":158.66,"quant":1.0,"sum":158.66,"sumAll":3086.82,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:26.579","offline":false}]}
  1151. 08.08 00:40:26.583 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,011 sec; average speed = 0,034 sec; position test num = 1419.0; product item 01112; <11>
  1152. 08.08 00:40:26.583 INFO  [CommonLogger] busy = false
  1153. 08.08 00:40:26.595 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1154. 08.08 00:40:26.596 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1155. 08.08 00:40:26.596 INFO  [TextCustomerDisplayPluginAbstract] *Йогурт ябло 1 158.66*
  1156. 08.08 00:40:26.596 INFO  [TextCustomerDisplayPluginAbstract] *Итого        3086.82*
  1157. 08.08 00:40:26.596 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1158. 08.08 00:40:26.596 INFO  [TextCustomerDisplayPluginAbstract]
  1159. 08.08 00:40:28.220 INFO  [Scale] BarcodeScannerImpl - barcode = 6908044000007
  1160. 08.08 00:40:28.220 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1161. 08.08 00:40:28.228 INFO  [TechProcessImpl] eventBarcodeScanner 6908044000007
  1162. 08.08 00:40:28.229 TRACE [MLServiceImpl] entering isEnabled()
  1163. 08.08 00:40:28.229 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1164. 08.08 00:40:28.229 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "6908044000007"
  1165. 08.08 00:40:28.229 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1166. 08.08 00:40:28.229 TRACE [SCService] entering isEnabled()
  1167. 08.08 00:40:28.229 TRACE [SCService] leaving isEnabled(). the result is: true
  1168. 08.08 00:40:28.229 TRACE [SCService] entering isSmChCoupon(String). The argument is: "6908044000007"
  1169. 08.08 00:40:28.229 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1170. 08.08 00:40:28.229 TRACE [MLServiceImpl] entering isEnabled()
  1171. 08.08 00:40:28.229 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1172. 08.08 00:40:28.229 TRACE [SCService] entering isEnabled()
  1173. 08.08 00:40:28.229 TRACE [SCService] leaving isEnabled(). the result is: true
  1174. 08.08 00:40:28.229 INFO  [CheckContainer] Barcode 6908044000007 has been received by visualisation
  1175. 08.08 00:40:28.235 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1176. 08.08 00:40:28.235 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 01112; type: ProductPieceEntity; count: 1000; sum: 15866; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1177. 08.08 00:40:28.248 INFO  [SpeedLog] TP addPosition time = 12 ms
  1178. 08.08 00:40:28.251 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,022 sec; average speed = 0,028 sec; position test num = 521; <22>
  1179. 08.08 00:40:28.251 INFO  [CheckContainer] visualization will start searching product
  1180. 08.08 00:40:28.252 INFO  [TechProcessImpl] TP searchProduct 6908044000007
  1181. 08.08 00:40:28.252 INFO  [CatalogService] getGoodsByBarCode barcode = 6908044000007
  1182. 08.08 00:40:28.253 INFO  [CatalogService] get product by barcode '6908044000007' result: ProductPieceEntity[name=Хлеб клубничный сладкий (Китай), item=08044]
  1183. 08.08 00:40:28.253 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 6908044000007 time = 1 ms
  1184. 08.08 00:40:28.253 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 6908044000007 time = 1 ms
  1185. 08.08 00:40:28.255 INFO  [SpeedLog] getProductRestrictions  time = 2 ms
  1186. 08.08 00:40:28.257 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 6908044000007 time = 5 ms
  1187. 08.08 00:40:28.257 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 6908044000007 time = 5 ms
  1188. 08.08 00:40:28.257 INFO  [SpeedLog] searchProduct time  time = 5 ms
  1189. 08.08 00:40:28.270 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,012 sec; average speed = 0,034 sec; position test num = 1420.0; product item 08044; <12>
  1190. 08.08 00:40:28.270 INFO  [CommonLogger] busy = false
  1191. 08.08 00:40:28.271 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":7,"barcode":"6908044000007","item":"08044","name":"Хлеб клубничный сладкий (Китай","price":1098.43,"quant":1.0,"sum":1098.43,"sumAll":4185.25,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:28.270","offline":false}]}
  1192. 08.08 00:40:28.284 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1193. 08.08 00:40:28.284 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1194. 08.08 00:40:28.284 INFO  [TextCustomerDisplayPluginAbstract] *Хлеб клубн 1 1098.43*
  1195. 08.08 00:40:28.285 INFO  [TextCustomerDisplayPluginAbstract] *Итого        4185.25*
  1196. 08.08 00:40:28.285 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1197. 08.08 00:40:28.285 INFO  [TextCustomerDisplayPluginAbstract]
  1198. 08.08 00:40:28.535 DEBUG [TechProcessImpl] Server online mode
  1199. 08.08 00:40:29.942 INFO  [Scale] BarcodeScannerImpl - barcode = 3007241000001
  1200. 08.08 00:40:29.942 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1201. 08.08 00:40:29.947 INFO  [TechProcessImpl] eventBarcodeScanner 3007241000001
  1202. 08.08 00:40:29.949 TRACE [MLServiceImpl] entering isEnabled()
  1203. 08.08 00:40:29.949 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1204. 08.08 00:40:29.949 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "3007241000001"
  1205. 08.08 00:40:29.949 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1206. 08.08 00:40:29.949 TRACE [SCService] entering isEnabled()
  1207. 08.08 00:40:29.949 TRACE [SCService] leaving isEnabled(). the result is: true
  1208. 08.08 00:40:29.949 TRACE [SCService] entering isSmChCoupon(String). The argument is: "3007241000001"
  1209. 08.08 00:40:29.949 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1210. 08.08 00:40:29.949 TRACE [MLServiceImpl] entering isEnabled()
  1211. 08.08 00:40:29.949 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1212. 08.08 00:40:29.949 TRACE [SCService] entering isEnabled()
  1213. 08.08 00:40:29.949 TRACE [SCService] leaving isEnabled(). the result is: true
  1214. 08.08 00:40:29.949 INFO  [CheckContainer] Barcode 3007241000001 has been received by visualisation
  1215. 08.08 00:40:29.951 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1216. 08.08 00:40:29.952 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 08044; type: ProductPieceEntity; count: 1000; sum: 109843; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1217. 08.08 00:40:29.966 INFO  [SpeedLog] TP addPosition time = 14 ms
  1218. 08.08 00:40:29.970 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,021 sec; average speed = 0,028 sec; position test num = 522; <21>
  1219. 08.08 00:40:29.970 INFO  [CheckContainer] visualization will start searching product
  1220. 08.08 00:40:29.970 INFO  [TechProcessImpl] TP searchProduct 3007241000001
  1221. 08.08 00:40:29.973 INFO  [CatalogService] getGoodsByBarCode barcode = 3007241000001
  1222. 08.08 00:40:29.974 INFO  [CatalogService] get product by barcode '3007241000001' result: ProductPieceEntity[name=Кефир клубничный соленый (Франция), item=07241]
  1223. 08.08 00:40:29.974 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 3007241000001 time = 1 ms
  1224. 08.08 00:40:29.974 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 3007241000001 time = 1 ms
  1225. 08.08 00:40:29.974 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  1226. 08.08 00:40:29.975 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 3007241000001 time = 2 ms
  1227. 08.08 00:40:29.975 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 3007241000001 time = 2 ms
  1228. 08.08 00:40:29.975 INFO  [SpeedLog] searchProduct time  time = 2 ms
  1229. 08.08 00:40:29.986 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":8,"barcode":"3007241000001","item":"07241","name":"Кефир клубничный соленый (Фран","price":929.69,"quant":1.0,"sum":929.69,"sumAll":5114.94,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:29.986","offline":false}]}
  1230. 08.08 00:40:29.990 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,014 sec; average speed = 0,034 sec; position test num = 1421.0; product item 07241; <14>
  1231. 08.08 00:40:29.990 INFO  [CommonLogger] busy = false
  1232. 08.08 00:40:30.005 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1233. 08.08 00:40:30.005 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1234. 08.08 00:40:30.005 INFO  [TextCustomerDisplayPluginAbstract] *Кефир клубн 1 929.69*
  1235. 08.08 00:40:30.005 INFO  [TextCustomerDisplayPluginAbstract] *Итого        5114.94*
  1236. 08.08 00:40:30.005 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1237. 08.08 00:40:30.005 INFO  [TextCustomerDisplayPluginAbstract]
  1238. 08.08 00:40:31.658 INFO  [Scale] BarcodeScannerImpl - barcode = 8006310000008
  1239. 08.08 00:40:31.658 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1240. 08.08 00:40:31.663 INFO  [TechProcessImpl] eventBarcodeScanner 8006310000008
  1241. 08.08 00:40:31.664 TRACE [MLServiceImpl] entering isEnabled()
  1242. 08.08 00:40:31.664 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1243. 08.08 00:40:31.664 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "8006310000008"
  1244. 08.08 00:40:31.664 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1245. 08.08 00:40:31.664 TRACE [SCService] entering isEnabled()
  1246. 08.08 00:40:31.664 TRACE [SCService] leaving isEnabled(). the result is: true
  1247. 08.08 00:40:31.664 TRACE [SCService] entering isSmChCoupon(String). The argument is: "8006310000008"
  1248. 08.08 00:40:31.664 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1249. 08.08 00:40:31.664 TRACE [MLServiceImpl] entering isEnabled()
  1250. 08.08 00:40:31.664 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1251. 08.08 00:40:31.665 TRACE [SCService] entering isEnabled()
  1252. 08.08 00:40:31.665 TRACE [SCService] leaving isEnabled(). the result is: true
  1253. 08.08 00:40:31.665 INFO  [CheckContainer] Barcode 8006310000008 has been received by visualisation
  1254. 08.08 00:40:31.668 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1255. 08.08 00:40:31.668 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 07241; type: ProductPieceEntity; count: 1000; sum: 92969; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1256. 08.08 00:40:31.678 INFO  [SpeedLog] TP addPosition time = 10 ms
  1257. 08.08 00:40:31.680 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,015 sec; average speed = 0,028 sec; position test num = 523; <15>
  1258. 08.08 00:40:31.680 INFO  [CheckContainer] visualization will start searching product
  1259. 08.08 00:40:31.680 INFO  [TechProcessImpl] TP searchProduct 8006310000008
  1260. 08.08 00:40:31.681 INFO  [CatalogService] getGoodsByBarCode barcode = 8006310000008
  1261. 08.08 00:40:31.681 INFO  [CatalogService] get product by barcode '8006310000008' result: ProductPieceEntity[name=Шоколад яблочный терпкий (Италия), item=06310]
  1262. 08.08 00:40:31.681 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 8006310000008 time = 0 ms
  1263. 08.08 00:40:31.681 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 8006310000008 time = 0 ms
  1264. 08.08 00:40:31.683 INFO  [SpeedLog] getProductRestrictions  time = 2 ms
  1265. 08.08 00:40:31.683 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 8006310000008 time = 2 ms
  1266. 08.08 00:40:31.684 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 8006310000008 time = 3 ms
  1267. 08.08 00:40:31.684 INFO  [SpeedLog] searchProduct time  time = 3 ms
  1268. 08.08 00:40:31.694 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,010 sec; average speed = 0,034 sec; position test num = 1422.0; product item 06310; <10>
  1269. 08.08 00:40:31.694 INFO  [CommonLogger] busy = false
  1270. 08.08 00:40:31.695 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":9,"barcode":"8006310000008","item":"06310","name":"Шоколад яблочный терпкий (Итал","price":782.92,"quant":1.0,"sum":782.92,"sumAll":5897.86,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:31.695","offline":false}]}
  1271. 08.08 00:40:31.703 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1272. 08.08 00:40:31.704 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1273. 08.08 00:40:31.704 INFO  [TextCustomerDisplayPluginAbstract] *Шоколад ябл 1 782.92*
  1274. 08.08 00:40:31.704 INFO  [TextCustomerDisplayPluginAbstract] *Итого        5897.86*
  1275. 08.08 00:40:31.704 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1276. 08.08 00:40:31.704 INFO  [TextCustomerDisplayPluginAbstract]
  1277. 08.08 00:40:33.353 INFO  [Scale] BarcodeScannerImpl - barcode = 5004902000002
  1278. 08.08 00:40:33.353 INFO  [CompositeBarcodeProcessor] Cash must be in state search product. Current state: ADD_POSITION
  1279. 08.08 00:40:33.360 INFO  [TechProcessImpl] eventBarcodeScanner 5004902000002
  1280. 08.08 00:40:33.362 TRACE [MLServiceImpl] entering isEnabled()
  1281. 08.08 00:40:33.362 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1282. 08.08 00:40:33.362 TRACE [MLServiceImpl] entering isMlCoupon(String). The argument is: "5004902000002"
  1283. 08.08 00:40:33.362 TRACE [MLServiceImpl] leaving isMlCoupon(String). The result is: false
  1284. 08.08 00:40:33.362 TRACE [SCService] entering isEnabled()
  1285. 08.08 00:40:33.362 TRACE [SCService] leaving isEnabled(). the result is: true
  1286. 08.08 00:40:33.362 TRACE [SCService] entering isSmChCoupon(String). The argument is: "5004902000002"
  1287. 08.08 00:40:33.362 TRACE [SCService] leaving isSmChCoupon(String). The result is: false
  1288. 08.08 00:40:33.362 TRACE [MLServiceImpl] entering isEnabled()
  1289. 08.08 00:40:33.362 TRACE [MLServiceImpl] leaving isEnabled(). the result is: true
  1290. 08.08 00:40:33.362 TRACE [SCService] entering isEnabled()
  1291. 08.08 00:40:33.362 TRACE [SCService] leaving isEnabled(). the result is: true
  1292. 08.08 00:40:33.362 INFO  [CheckContainer] Barcode 5004902000002 has been received by visualisation
  1293. 08.08 00:40:33.364 INFO  [CheckContainer] All conditions are checked. Current position will be added
  1294. 08.08 00:40:33.368 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 06310; type: ProductPieceEntity; count: 1000; sum: 78292; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1295. 08.08 00:40:33.377 INFO  [SpeedLog] TP addPosition time = 9 ms
  1296. 08.08 00:40:33.385 INFO  [SpeedLog] (CHECK_CONTAINER) product and product container was found = 0,023 sec; average speed = 0,028 sec; position test num = 524; <23>
  1297. 08.08 00:40:33.386 INFO  [CheckContainer] visualization will start searching product
  1298. 08.08 00:40:33.387 INFO  [TechProcessImpl] TP searchProduct 5004902000002
  1299. 08.08 00:40:33.387 INFO  [CatalogService] getGoodsByBarCode barcode = 5004902000002
  1300. 08.08 00:40:33.389 INFO  [CatalogService] get product by barcode '5004902000002' result: ProductPieceEntity[name=Йогурт малиновый горький (Великобритания), item=04902]
  1301. 08.08 00:40:33.389 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode, barcode = 5004902000002 time = 2 ms
  1302. 08.08 00:40:33.389 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode before check restrictions, barcode = 5004902000002 time = 2 ms
  1303. 08.08 00:40:33.389 INFO  [SpeedLog] getProductRestrictions  time = 0 ms
  1304. 08.08 00:40:33.390 INFO  [SpeedLog] CatalogGoods: dataFinder.getProductByBarcode after check restrictions, barcode = 5004902000002 time = 3 ms
  1305. 08.08 00:40:33.390 INFO  [SpeedLog] CatalogGoods#getGoodsByBarCode, barcode = 5004902000002 time = 3 ms
  1306. 08.08 00:40:33.390 INFO  [SpeedLog] searchProduct time  time = 3 ms
  1307. 08.08 00:40:33.401 INFO  [PrismaBridgeImpl] {"events":[{"prefix":"KKM","shop":7171,"cash":61,"mode":67,"tabNumber":"1","cashier":"Администраторов А.А.","purchase":183,"pos":10,"barcode":"5004902000002","item":"04902","name":"Йогурт малиновый горький (Вели","price":548.4,"quant":1.0,"sum":548.4,"sumAll":6446.26,"cardType":"","cardNumber":"","discount":0.0,"discountAll":0.0,"dateTime":"08.08.2019 00:40:33.401","offline":false}]}
  1308. 08.08 00:40:33.402 INFO  [SpeedLog] (CHECK_CONTAINER) show product container time = 0,012 sec; average speed = 0,034 sec; position test num = 1423.0; product item 04902; <12>
  1309. 08.08 00:40:33.402 INFO  [CommonLogger] busy = false
  1310. 08.08 00:40:33.409 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1311. 08.08 00:40:33.409 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1312. 08.08 00:40:33.409 INFO  [TextCustomerDisplayPluginAbstract] *Йогурт мали 1 548.40*
  1313. 08.08 00:40:33.409 INFO  [TextCustomerDisplayPluginAbstract] *Итого        6446.26*
  1314. 08.08 00:40:33.409 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1315. 08.08 00:40:33.409 INFO  [TextCustomerDisplayPluginAbstract]
  1316. 08.08 00:40:33.437 INFO  [TechProcessImpl] TechProcess add position id: null; number: 1; item: 04902; type: ProductPieceEntity; count: 1000; sum: 54840; sumDiscount: 0; dateTime: (NULL); num-in-original: null
  1317. 08.08 00:40:33.492 INFO  [SpeedLog] TP addPosition time = 54 ms
  1318. 08.08 00:40:33.742 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1319. 08.08 00:40:33.743 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1320. 08.08 00:40:33.743 INFO  [TextCustomerDisplayPluginAbstract] *Йогурт мали 1 548.40*
  1321. 08.08 00:40:33.743 INFO  [TextCustomerDisplayPluginAbstract] *Итого        6446.26*
  1322. 08.08 00:40:33.743 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1323. 08.08 00:40:33.743 INFO  [TextCustomerDisplayPluginAbstract]
  1324. 08.08 00:40:33.771 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  1325. 08.08 00:40:33.974 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=32, command=kbdSubtotal]
  1326. 08.08 00:40:33.997 INFO  [CommonLogger] busy = true
  1327. 08.08 00:40:34.022 TRACE [TechProcessImpl] Start warn divide alco
  1328. 08.08 00:40:34.022 TRACE [TechProcessImpl] End warn devide alco
  1329. 08.08 00:40:34.162 INFO  [TechProcessImpl] goToDiscounts
  1330. 08.08 00:40:34.665 INFO  [LoyalBridgeServiceImpl] --------------- begin discount calculation ---------------
  1331. 08.08 00:40:34.805 INFO  [LoyalProductFinder] Time finding items (10) = 43 ms
  1332. 08.08 00:40:34.806 INFO  [LoyalProductsConverter] Time searching loyal goods for 10 productItems = 44 ms
  1333. 08.08 00:40:34.806 INFO  [LoyalCalculatorConverter] Time converting 10 positions = 0 ms
  1334. 08.08 00:40:34.806 TRACE [MLServiceImpl] entering getMlCardNo(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1335. 08.08 00:40:34.806 TRACE [MLServiceImpl] leaving getMlCardNo(Purchase). The receipt does not have cards applied
  1336. 08.08 00:40:34.806 TRACE [MLServiceImpl] entering getMlCouponNo(PurchaseEntity). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1337. 08.08 00:40:34.806 TRACE [MLServiceImpl] leaving getMlCouponNo(PurchaseEntity). The receipt does not have cards applied
  1338. 08.08 00:40:34.807 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  1339. 08.08 00:40:34.807 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  1340. 08.08 00:40:34.856 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  1341. 08.08 00:40:34.857 TRACE [LoyPluginEmulator] entering doDiscount(Receipt). The argument is: ru.crystals.api.commons.ReceiptPurchaseWrapper@9bcc04
  1342. 08.08 00:40:34.858 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  1343. 08.08 00:40:34.858 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  1344. 08.08 00:40:34.858 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, cardProcessingId='null'}; it took 0 [ms]
  1345. 08.08 00:40:34.859 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: "02800"; qnty: 1000; sum: 26227; min-sum: 0; discountable: true], emul-pos [no: 2; marking: "00310"; qnty: 1000; sum: 292; min-sum: 0; discountable: true], emul-pos [no: 3; marking: "08496"; qnty: 1000; sum: 113145; min-sum: 0; discountable: true], emul-pos [no: 4; marking: "09246"; qnty: 1000; sum: 125469; min-sum: 0; discountable: true], emul-pos [no: 5; marking: "02021"; qnty: 1000; sum: 27683; min-sum: 0; discountable: true], emul-pos [no: 6; marking: "01112"; qnty: 1000; sum: 15866; min-sum: 0; discountable: true], emul-pos [no: 7; marking: "08044"; qnty: 1000; sum: 109843; min-sum: 0; discountable: true], emul-pos [no: 8; marking: "07241"; qnty: 1000; sum: 92969; min-sum: 0; discountable: true], emul-pos [no: 9; marking: "06310"; qnty: 1000; sum: 78292; min-sum: 0; discountable: true], emul-pos [no: 10; marking: "04902"; qnty: 1000; sum: 54840; min-sum: 0; discountable: true]]]
  1346. 08.08 00:40:34.889 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  1347. 08.08 00:40:34.896 TRACE [LoyPluginEmulator] leaving makeCalcCalls(List, EmulatorReceipt). The result is: emul-loy-result [discounts: []; limit: null; taken-into-account: null]; it took 37 [ms]
  1348. 08.08 00:40:34.896 TRACE [LoyPluginEmulator] leaving doDiscount(Receipt). The result is: LoyaltyResult{discounts=null, bonusWriteOffsLimits=null, bonusesTakenIntoAccount=null, bonusAccrualResults=null, printDocuments=null, messagesToCashier=null, extendedAttributeMap=null}; it took 39 [ms]
  1349. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1350. Quantity 1000
  1351. Position sum 262.27
  1352. Value 0
  1353. Min price 0.00
  1354. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1355. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1356. Quantity 1000
  1357. Position sum 2.92
  1358. Value 0
  1359. Min price 0.00
  1360. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1361. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1362. Quantity 1000
  1363. Position sum 1131.45
  1364. Value 0
  1365. Min price 0.00
  1366. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1367. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1368. Quantity 1000
  1369. Position sum 1254.69
  1370. Value 0
  1371. Min price 0.00
  1372. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1373. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1374. Quantity 1000
  1375. Position sum 276.83
  1376. Value 0
  1377. Min price 0.00
  1378. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1379. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1380. Quantity 1000
  1381. Position sum 158.66
  1382. Value 0
  1383. Min price 0.00
  1384. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1385. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1386. Quantity 1000
  1387. Position sum 1098.43
  1388. Value 0
  1389. Min price 0.00
  1390. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1391. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1392. Quantity 1000
  1393. Position sum 929.69
  1394. Value 0
  1395. Min price 0.00
  1396. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1397. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1398. Quantity 1000
  1399. Position sum 782.92
  1400. Value 0
  1401. Min price 0.00
  1402. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1403. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1404. Quantity 1000
  1405. Position sum 548.40
  1406. Value 0
  1407. Min price 0.00
  1408. 08.08 00:40:34.897 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1409. 08.08 00:40:34.898 TRACE [MLServiceImpl] entering getMlCardNo(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1410. 08.08 00:40:34.898 TRACE [MLServiceImpl] leaving getMlCardNo(Purchase). The receipt does not have cards applied
  1411. 08.08 00:40:34.898 TRACE [MLServiceImpl] entering getMlCouponNo(PurchaseEntity). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1412. 08.08 00:40:34.898 TRACE [MLServiceImpl] leaving getMlCouponNo(PurchaseEntity). The receipt does not have cards applied
  1413. 08.08 00:40:34.898 TRACE [SCService] entering isEnabled()
  1414. 08.08 00:40:34.898 TRACE [SCService] leaving isEnabled(). the result is: true
  1415. 08.08 00:40:34.898 TRACE [SCService] entering calcDiscount(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1416. 08.08 00:40:34.903 TRACE [SCService] Send request <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1417. <ChequeRequest xmlns="http://smartcheckout.ru/xsd/s10ren.xsd" ChequeType="Soft">
  1418.     <RequestID>1565214019500</RequestID>
  1419.     <DateTime>2019-08-08T00:40:34.898+03:00</DateTime>
  1420.     <POS>61</POS>
  1421.     <Number>1565214019500</Number>
  1422.     <Summ>6446.26</Summ>
  1423.     <Discount>0.000</Discount>
  1424.     <SummDiscounted>6446.26</SummDiscounted>
  1425.     <Item>
  1426.         <PositionNumber>1</PositionNumber>
  1427.         <Article>02800</Article>
  1428.         <ArticleName>Шоколад малиновый пряный (Испания)</ArticleName>
  1429.         <Price>262.27</Price>
  1430.         <Quantity>1.000</Quantity>
  1431.         <Summ>262.27</Summ>
  1432.         <Discount>0.000</Discount>
  1433.         <SummDiscounted>262.27</SummDiscounted>
  1434.     </Item>
  1435.     <Item>
  1436.         <PositionNumber>2</PositionNumber>
  1437.         <Article>00310</Article>
  1438.         <ArticleName>Шоколад яблочный терпкий (Россия)</ArticleName>
  1439.         <Price>2.92</Price>
  1440.         <Quantity>1.000</Quantity>
  1441.         <Summ>2.92</Summ>
  1442.         <Discount>0.000</Discount>
  1443.         <SummDiscounted>2.92</SummDiscounted>
  1444.     </Item>
  1445.     <Item>
  1446.         <PositionNumber>3</PositionNumber>
  1447.         <Article>08496</Article>
  1448.         <ArticleName>Напиток вишневый густой (Китай)</ArticleName>
  1449.         <Price>1131.45</Price>
  1450.         <Quantity>1.000</Quantity>
  1451.         <Summ>1131.45</Summ>
  1452.         <Discount>0.000</Discount>
  1453.         <SummDiscounted>1131.45</SummDiscounted>
  1454.     </Item>
  1455.     <Item>
  1456.         <PositionNumber>4</PositionNumber>
  1457.         <Article>09246</Article>
  1458.         <ArticleName>Напиток клубничный соленый (Бельгия)</ArticleName>
  1459.         <Price>1254.69</Price>
  1460.         <Quantity>1.000</Quantity>
  1461.         <Summ>1254.69</Summ>
  1462.         <Discount>0.000</Discount>
  1463.         <SummDiscounted>1254.69</SummDiscounted>
  1464.     </Item>
  1465.     <Item>
  1466.         <PositionNumber>5</PositionNumber>
  1467.         <Article>02021</Article>
  1468.         <ArticleName>Кефир виноградный сладкий (Испания)</ArticleName>
  1469.         <Price>276.83</Price>
  1470.         <Quantity>1.000</Quantity>
  1471.         <Summ>276.83</Summ>
  1472.         <Discount>0.000</Discount>
  1473.         <SummDiscounted>276.83</SummDiscounted>
  1474.     </Item>
  1475.     <Item>
  1476.         <PositionNumber>6</PositionNumber>
  1477.         <Article>01112</Article>
  1478.         <ArticleName>Йогурт яблочный кислый (Израиль)</ArticleName>
  1479.         <Price>158.66</Price>
  1480.         <Quantity>1.000</Quantity>
  1481.         <Summ>158.66</Summ>
  1482.         <Discount>0.000</Discount>
  1483.         <SummDiscounted>158.66</SummDiscounted>
  1484.     </Item>
  1485.     <Item>
  1486.         <PositionNumber>7</PositionNumber>
  1487.         <Article>08044</Article>
  1488.         <ArticleName>Хлеб клубничный сладкий (Китай)</ArticleName>
  1489.         <Price>1098.43</Price>
  1490.         <Quantity>1.000</Quantity>
  1491.         <Summ>1098.43</Summ>
  1492.         <Discount>0.000</Discount>
  1493.         <SummDiscounted>1098.43</SummDiscounted>
  1494.     </Item>
  1495.     <Item>
  1496.         <PositionNumber>8</PositionNumber>
  1497.         <Article>07241</Article>
  1498.         <ArticleName>Кефир клубничный соленый (Франция)</ArticleName>
  1499.         <Price>929.69</Price>
  1500.         <Quantity>1.000</Quantity>
  1501.         <Summ>929.69</Summ>
  1502.         <Discount>0.000</Discount>
  1503.         <SummDiscounted>929.69</SummDiscounted>
  1504.     </Item>
  1505.     <Item>
  1506.         <PositionNumber>9</PositionNumber>
  1507.         <Article>06310</Article>
  1508.         <ArticleName>Шоколад яблочный терпкий (Италия)</ArticleName>
  1509.         <Price>782.92</Price>
  1510.         <Quantity>1.000</Quantity>
  1511.         <Summ>782.92</Summ>
  1512.         <Discount>0.000</Discount>
  1513.         <SummDiscounted>782.92</SummDiscounted>
  1514.     </Item>
  1515.     <Item>
  1516.         <PositionNumber>10</PositionNumber>
  1517.         <Article>04902</Article>
  1518.         <ArticleName>Йогурт малиновый горький (Великобритания)</ArticleName>
  1519.         <Price>548.40</Price>
  1520.         <Quantity>1.000</Quantity>
  1521.         <Summ>548.40</Summ>
  1522.         <Discount>0.000</Discount>
  1523.         <SummDiscounted>548.40</SummDiscounted>
  1524.     </Item>
  1525. </ChequeRequest>
  1526.  
  1527. 08.08 00:40:34.903 TRACE [SCService] entering getServices()
  1528. 08.08 00:40:34.903 TRACE [SCService] getting services (IN MEMORY)
  1529. 08.08 00:40:34.903 TRACE [SCService] leaving getServices(). The result size is: 2
  1530. 08.08 00:40:34.959 TRACE [SCService] Received response: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1531. <ChequeRequestResponce xmlns="http://smartcheckout.ru/xsd/s10ren.xsd">
  1532.     <RequestID>1565214019500</RequestID>
  1533.     <Processed>2019-08-08T00:40:34.950+03:00</Processed>
  1534.     <ReturnCode>0</ReturnCode>
  1535.     <CashierMessageTO>0</CashierMessageTO>
  1536.     <Summ>6446.26</Summ>
  1537.     <Discount>0.000</Discount>
  1538.     <SummDiscounted>6446.26</SummDiscounted>
  1539.     <Item>
  1540.         <PositionNumber>1</PositionNumber>
  1541.         <Article>02800</Article>
  1542.         <ArticleName>Шоколад малиновый пряный (Испания)</ArticleName>
  1543.         <Price>262.27</Price>
  1544.         <MinPrice>0</MinPrice>
  1545.         <Quantity>1.000</Quantity>
  1546.         <Summ>262.27</Summ>
  1547.         <Discount>0.000</Discount>
  1548.         <SummDiscounted>262.27</SummDiscounted>
  1549.     </Item>
  1550.     <Item>
  1551.         <PositionNumber>2</PositionNumber>
  1552.         <Article>00310</Article>
  1553.         <ArticleName>Шоколад яблочный терпкий (Россия)</ArticleName>
  1554.         <Price>2.92</Price>
  1555.         <MinPrice>0</MinPrice>
  1556.         <Quantity>1.000</Quantity>
  1557.         <Summ>2.92</Summ>
  1558.         <Discount>0.000</Discount>
  1559.         <SummDiscounted>2.92</SummDiscounted>
  1560.     </Item>
  1561.     <Item>
  1562.         <PositionNumber>3</PositionNumber>
  1563.         <Article>08496</Article>
  1564.         <ArticleName>Напиток вишневый густой (Китай)</ArticleName>
  1565.         <Price>1131.45</Price>
  1566.         <MinPrice>0</MinPrice>
  1567.         <Quantity>1.000</Quantity>
  1568.         <Summ>1131.45</Summ>
  1569.         <Discount>0.000</Discount>
  1570.         <SummDiscounted>1131.45</SummDiscounted>
  1571.     </Item>
  1572.     <Item>
  1573.         <PositionNumber>4</PositionNumber>
  1574.         <Article>09246</Article>
  1575.         <ArticleName>Напиток клубничный соленый (Бельгия)</ArticleName>
  1576.         <Price>1254.69</Price>
  1577.         <MinPrice>0</MinPrice>
  1578.         <Quantity>1.000</Quantity>
  1579.         <Summ>1254.69</Summ>
  1580.         <Discount>0.000</Discount>
  1581.         <SummDiscounted>1254.69</SummDiscounted>
  1582.     </Item>
  1583.     <Item>
  1584.         <PositionNumber>5</PositionNumber>
  1585.         <Article>02021</Article>
  1586.         <ArticleName>Кефир виноградный сладкий (Испания)</ArticleName>
  1587.         <Price>276.83</Price>
  1588.         <MinPrice>0</MinPrice>
  1589.         <Quantity>1.000</Quantity>
  1590.         <Summ>276.83</Summ>
  1591.         <Discount>0.000</Discount>
  1592.         <SummDiscounted>276.83</SummDiscounted>
  1593.     </Item>
  1594.     <Item>
  1595.         <PositionNumber>6</PositionNumber>
  1596.         <Article>01112</Article>
  1597.         <ArticleName>Йогурт яблочный кислый (Израиль)</ArticleName>
  1598.         <Price>158.66</Price>
  1599.         <MinPrice>0</MinPrice>
  1600.         <Quantity>1.000</Quantity>
  1601.         <Summ>158.66</Summ>
  1602.         <Discount>0.000</Discount>
  1603.         <SummDiscounted>158.66</SummDiscounted>
  1604.     </Item>
  1605.     <Item>
  1606.         <PositionNumber>7</PositionNumber>
  1607.         <Article>08044</Article>
  1608.         <ArticleName>Хлеб клубничный сладкий (Китай)</ArticleName>
  1609.         <Price>1098.43</Price>
  1610.         <MinPrice>0</MinPrice>
  1611.         <Quantity>1.000</Quantity>
  1612.         <Summ>1098.43</Summ>
  1613.         <Discount>0.000</Discount>
  1614.         <SummDiscounted>1098.43</SummDiscounted>
  1615.     </Item>
  1616.     <Item>
  1617.         <PositionNumber>8</PositionNumber>
  1618.         <Article>07241</Article>
  1619.         <ArticleName>Кефир клубничный соленый (Франция)</ArticleName>
  1620.         <Price>929.69</Price>
  1621.         <MinPrice>0</MinPrice>
  1622.         <Quantity>1.000</Quantity>
  1623.         <Summ>929.69</Summ>
  1624.         <Discount>0.000</Discount>
  1625.         <SummDiscounted>929.69</SummDiscounted>
  1626.     </Item>
  1627.     <Item>
  1628.         <PositionNumber>9</PositionNumber>
  1629.         <Article>06310</Article>
  1630.         <ArticleName>Шоколад яблочный терпкий (Италия)</ArticleName>
  1631.         <Price>782.92</Price>
  1632.         <MinPrice>0</MinPrice>
  1633.         <Quantity>1.000</Quantity>
  1634.         <Summ>782.92</Summ>
  1635.         <Discount>0.000</Discount>
  1636.         <SummDiscounted>782.92</SummDiscounted>
  1637.     </Item>
  1638.     <Item>
  1639.         <PositionNumber>10</PositionNumber>
  1640.         <Article>04902</Article>
  1641.         <ArticleName>Йогурт малиновый горький (Великобритания)</ArticleName>
  1642.         <Price>548.40</Price>
  1643.         <MinPrice>0</MinPrice>
  1644.         <Quantity>1.000</Quantity>
  1645.         <Summ>548.40</Summ>
  1646.         <Discount>0.000</Discount>
  1647.         <SummDiscounted>548.40</SummDiscounted>
  1648.     </Item>
  1649. </ChequeRequestResponce>
  1650.  
  1651. 08.08 00:40:34.959 TRACE [SCReceiptConverter] ml discounts: {position-key [marking: 01112; original-price: 15866]=0, position-key [marking: 09246; original-price: 125469]=0, position-key [marking: 02021; original-price: 27683]=0, position-key [marking: 00310; original-price: 292]=0, position-key [marking: 08044; original-price: 109843]=0, position-key [marking: 07241; original-price: 92969]=0, position-key [marking: 02800; original-price: 26227]=0, position-key [marking: 08496; original-price: 113145]=0, position-key [marking: 06310; original-price: 78292]=0, position-key [marking: 04902; original-price: 54840]=0}
  1652. 08.08 00:40:34.959 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 01112; original-price: 15866]]: SC discount value is: 0
  1653. 08.08 00:40:34.959 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 09246; original-price: 125469]]: SC discount value is: 0
  1654. 08.08 00:40:34.959 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 02021; original-price: 27683]]: SC discount value is: 0
  1655. 08.08 00:40:34.959 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 00310; original-price: 292]]: SC discount value is: 0
  1656. 08.08 00:40:34.959 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 08044; original-price: 109843]]: SC discount value is: 0
  1657. 08.08 00:40:34.959 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 07241; original-price: 92969]]: SC discount value is: 0
  1658. 08.08 00:40:34.960 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 02800; original-price: 26227]]: SC discount value is: 0
  1659. 08.08 00:40:34.960 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 08496; original-price: 113145]]: SC discount value is: 0
  1660. 08.08 00:40:34.960 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 06310; original-price: 78292]]: SC discount value is: 0
  1661. 08.08 00:40:34.960 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 04902; original-price: 54840]]: SC discount value is: 0
  1662. 08.08 00:40:34.960 TRACE [SCService] leaving calcDiscount(Purchase). The result is: Purchase{number=null, dateCreate=null, checkSum=644626, operationType=null, discountValueTotal=0}; it took 62 [ms]
  1663. 08.08 00:40:34.961 DEBUG [LoymaxUtils] Loymax request:
  1664. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLRequest><Version>3.2</Version><Calculates><CalculateRequest PurchaseID="71710611565214034960" OperationID="fec6ce7bb3f74da3b635aa4394827d63" OperationDate="2019-08-08T00:40:34.960+03:00" ElementID="1"><Cheque ChequeDate="2019-08-08T00:40:19.500+03:00"><ChequeLine PosID="17132" Amount="262.27" Name="Шоколад малиновый пряный (Испания)" GoodsId="02800" Price="262.27" Quantity="1.000"/><ChequeLine PosID="17133" Amount="2.92" Name="Шоколад яблочный терпкий (Россия)" GoodsId="00310" Price="2.92" Quantity="1.000"/><ChequeLine PosID="17134" Amount="1131.45" Name="Напиток вишневый густой (Китай)" GoodsId="08496" Price="1131.45" Quantity="1.000"/><ChequeLine PosID="17135" Amount="1254.69" Name="Напиток клубничный соленый (Бельгия)" GoodsId="09246" Price="1254.69" Quantity="1.000"/><ChequeLine PosID="17136" Amount="276.83" Name="Кефир виноградный сладкий (Испания)" GoodsId="02021" Price="276.83" Quantity="1.000"/><ChequeLine PosID="17137" Amount="158.66" Name="Йогурт яблочный кислый (Израиль)" GoodsId="01112" Price="158.66" Quantity="1.000"/><ChequeLine PosID="17138" Amount="1098.43" Name="Хлеб клубничный сладкий (Китай)" GoodsId="08044" Price="1098.43" Quantity="1.000"/><ChequeLine PosID="17139" Amount="929.69" Name="Кефир клубничный соленый (Франция)" GoodsId="07241" Price="929.69" Quantity="1.000"/><ChequeLine PosID="17240" Amount="782.92" Name="Шоколад яблочный терпкий (Италия)" GoodsId="06310" Price="782.92" Quantity="1.000"/><ChequeLine PosID="17241" Amount="548.40" Name="Йогурт малиновый горький (Великобритания)" GoodsId="04902" Price="548.40" Quantity="1.000"/></Cheque></CalculateRequest></Calculates></XMLRequest>
  1665.  
  1666. 08.08 00:40:35.094 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  1667. 08.08 00:40:35.098 DEBUG [LoymaxUtils] Loymax response:
  1668. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLResponse><ErrorCode>0</ErrorCode><Calculates><CalculateResponse AvailableAmount="6446.26" AvailableBonusAmount="0" ErrorCode="0"><Cheque ChequeDate="2019-08-08T00:40:19.500+03:00"><ChequeLine PosID="17132" Amount="262.27" Name="Шоколад малиновый пряный (Испания)" GoodsId="02800" Price="262.27" Quantity="1.000" Discount="0"/><ChequeLine PosID="17133" Amount="2.92" Name="Шоколад яблочный терпкий (Россия)" GoodsId="00310" Price="2.92" Quantity="1.000" Discount="0"/><ChequeLine PosID="17134" Amount="1131.45" Name="Напиток вишневый густой (Китай)" GoodsId="08496" Price="1131.45" Quantity="1.000" Discount="0"/><ChequeLine PosID="17135" Amount="1254.69" Name="Напиток клубничный соленый (Бельгия)" GoodsId="09246" Price="1254.69" Quantity="1.000" Discount="0"/><ChequeLine PosID="17136" Amount="276.83" Name="Кефир виноградный сладкий (Испания)" GoodsId="02021" Price="276.83" Quantity="1.000" Discount="0"/><ChequeLine PosID="17137" Amount="158.66" Name="Йогурт яблочный кислый (Израиль)" GoodsId="01112" Price="158.66" Quantity="1.000" Discount="0"/><ChequeLine PosID="17138" Amount="1098.43" Name="Хлеб клубничный сладкий (Китай)" GoodsId="08044" Price="1098.43" Quantity="1.000" Discount="0"/><ChequeLine PosID="17139" Amount="929.69" Name="Кефир клубничный соленый (Франция)" GoodsId="07241" Price="929.69" Quantity="1.000" Discount="0"/><ChequeLine PosID="17240" Amount="782.92" Name="Шоколад яблочный терпкий (Италия)" GoodsId="06310" Price="782.92" Quantity="1.000" Discount="0"/><ChequeLine PosID="17241" Amount="548.40" Name="Йогурт малиновый горький (Великобритания)" GoodsId="04902" Price="548.40" Quantity="1.000" Discount="0"/></Cheque></CalculateResponse></Calculates></XMLResponse>
  1669.  
  1670. 08.08 00:40:35.108 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  1671. 08.08 00:40:35.108 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  1672. 08.08 00:40:35.139 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1673. 08.08 00:40:35.140 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1674. 08.08 00:40:35.147 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1675. 08.08 00:40:35.148 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  1676. 08.08 00:40:35.256 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  1677. 08.08 00:40:35.262 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  1678. 08.08 00:40:35.262 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  1679. 08.08 00:40:35.263 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  1680. 08.08 00:40:35.272 INFO  [SetApiPluginLoyProvider] Plugin "ru.crystals.loy.plugin.emulator" does not do post discount tuning
  1681. 08.08 00:40:35.275 TRACE [MLServiceImpl] entering getMlCardNo(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1682. 08.08 00:40:35.275 TRACE [MLServiceImpl] leaving getMlCardNo(Purchase). The receipt does not have cards applied
  1683. 08.08 00:40:35.276 TRACE [MLServiceImpl] entering getMlCouponNo(PurchaseEntity). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1684. 08.08 00:40:35.276 TRACE [MLServiceImpl] leaving getMlCouponNo(PurchaseEntity). The receipt does not have cards applied
  1685. 08.08 00:40:35.276 INFO  [LoyalServiceImpl] Discount calculation (Purchase #183; Positions: 10
  1686. 08.08 00:40:35.282 WARN  [LoyalServiceImpl] extractNonDiscountRelatedFields: the argument is NULL! Null will be returned!
  1687. 08.08 00:40:35.353 INFO  [LoyalBridgeServiceImpl] Total time of discount calculation = 617 ms
  1688. 08.08 00:40:35.354 INFO  [LoyalBridgeServiceImpl] ---------------- end discount calculation ----------------
  1689. 08.08 00:40:35.367 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  1690. 08.08 00:40:35.367 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1691. 08.08 00:40:35.367 INFO  [TextCustomerDisplayPluginAbstract] *Скидка          0.00*
  1692. 08.08 00:40:35.367 INFO  [TextCustomerDisplayPluginAbstract] *Итого        6446.26*
  1693. 08.08 00:40:35.367 INFO  [TextCustomerDisplayPluginAbstract] **********************
  1694. 08.08 00:40:35.367 INFO  [TextCustomerDisplayPluginAbstract]
  1695. 08.08 00:40:35.405 INFO  [SpeedLog] TechProcess discounts processing on cheque with 10 positions [sale] time = 1243 ms
  1696. 08.08 00:40:35.407 INFO  [CommonLogger] value = 0
  1697. 08.08 00:40:35.460 TRACE [TechProcessImpl] Start warn divide amount
  1698. 08.08 00:40:35.477 INFO  [TechProcessImpl] goToPayments
  1699. 08.08 00:40:35.487 INFO  [CheckContainer] startPayments() surcharge = 644626
  1700. 08.08 00:40:35.495 INFO  [CheckContainer] isPaymentComplete = false
  1701. 08.08 00:40:35.495 INFO  [CheckContainer] prevState = ADD_POSITION
  1702. 08.08 00:40:35.496 INFO  [CheckContainer] paid = 0
  1703. 08.08 00:40:35.496 INFO  [CheckContainer] surcharge = 644626
  1704. 08.08 00:40:35.496 INFO  [CheckContainer] getPaymentFiscalizeError = NONE
  1705. 08.08 00:40:35.496 INFO  [CheckContainer] Current payment container is ru.crystals.pos.visualization.payments.cash.CashPaymentContainer
  1706. 08.08 00:40:35.504 INFO  [CommonLogger] busy = false
  1707. 08.08 00:40:35.504 INFO  [SpeedLog] (SUBTOTAL) time = 1,506;
  1708. 08.08 00:40:35.505 INFO  [CommonLogger] busy = false
  1709. 08.08 00:40:35.662 INFO  [FiscalPrinter] throwException(ManualFiscalPrinterException [exceptionArea: CLOSE_CHECK_BEFORE_SAVE, fatal is false, Message: ""])
  1710. 08.08 00:40:35.690 INFO  [TechProcessImpl] eventFunctionKey: FunctionKey [scanCode=80, command=kbdMenu5]
  1711. 08.08 00:40:35.895 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  1712. 08.08 00:40:35.895 INFO  [CommonLogger] Menu command: Типы оплат (class ru.crystals.pos.visualization.menu.commands.PaymentTypeCommand)
  1713. 08.08 00:40:35.932 ERROR [CommonLogger] isAllowedToApplySelectedPayment: the  selected payment [id: BonusCardPaymentEntity; bank-id: ] is NOT allowed to be used (maybe it was not configured properly yet)
  1714. 08.08 00:40:35.932 ERROR [CommonLogger] isAllowedToApplySelectedPayment: the  selected payment [id: CFTGiftCardPaymentEntity; bank-id: ] is NOT allowed to be used (maybe it was not configured properly yet)
  1715. 08.08 00:40:35.937 ERROR [CommonLogger] isAllowedToApplySelectedPayment: the  selected payment [id: CFTEGCPaymentEntity; bank-id: ] is NOT allowed to be used (maybe it was not configured properly yet)
  1716. 08.08 00:40:35.951 ERROR [CommonLogger] isAllowedToApplySelectedPayment: the  selected payment [id: ChildrenCardPaymentEntity; bank-id: Эмулятор детских карт] is NOT allowed to be used (maybe it was not configured properly yet)
  1717. 08.08 00:40:35.951 INFO  [SpeedLog] CheckPaymentTypesContainer#getPaymentStrings return   Наличные payment types in  time = 52 ms
  1718. 08.08 00:40:36.099 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1719. 08.08 00:40:36.300 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1720. 08.08 00:40:36.502 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1721. 08.08 00:40:36.704 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1722. 08.08 00:40:36.906 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1723. 08.08 00:40:37.107 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1724. 08.08 00:40:37.308 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1725. 08.08 00:40:37.512 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1726. 08.08 00:40:37.712 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=40, command=kbdDown]
  1727. 08.08 00:40:37.915 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  1728. 08.08 00:40:37.935 INFO  [CheckContainer] isPaymentComplete = false
  1729. 08.08 00:40:37.936 INFO  [CheckContainer] prevState = ADD_PAYMENT
  1730. 08.08 00:40:37.936 INFO  [CheckContainer] paid = 0
  1731. 08.08 00:40:37.936 INFO  [CheckContainer] surcharge = 644626
  1732. 08.08 00:40:37.936 INFO  [CheckContainer] getPaymentFiscalizeError = NONE
  1733. 08.08 00:40:37.937 INFO  [CheckContainer] Current payment container is ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentPluginAdapter
  1734. 08.08 00:40:37.938 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_AUTH_CODE, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=745129, sumPayBaseCurrency=745129, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  1735. 08.08 00:40:37.938 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_AUTH_CODE, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=745129, sumPayBaseCurrency=745129, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  1736. 08.08 00:40:37.938 INFO  [AbstractPaymentModel] Setting payment: PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}
  1737. 08.08 00:40:37.938 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_AUTH_CODE, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=745129, sumPayBaseCurrency=745129, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  1738. 08.08 00:40:37.938 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_SUM, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  1739. 08.08 00:40:37.959 INFO  [CommonLogger] busy = true
  1740. 08.08 00:40:37.961 TRACE [TechProcessImpl] Start warn divide alco
  1741. 08.08 00:40:37.961 TRACE [TechProcessImpl] End warn devide alco
  1742. 08.08 00:40:37.964 INFO  [TechProcessImpl] goToDiscounts
  1743. 08.08 00:40:38.128 INFO  [LoyalBridgeServiceImpl] --------------- begin discount calculation ---------------
  1744. 08.08 00:40:38.134 INFO  [LoyalProductFinder] Time finding items (10) = 6 ms
  1745. 08.08 00:40:38.134 INFO  [LoyalProductsConverter] Time searching loyal goods for 10 productItems = 6 ms
  1746. 08.08 00:40:38.134 INFO  [LoyalCalculatorConverter] Time converting 10 positions = 0 ms
  1747. 08.08 00:40:38.135 TRACE [MLServiceImpl] entering getMlCardNo(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1748. 08.08 00:40:38.135 TRACE [MLServiceImpl] leaving getMlCardNo(Purchase). The receipt does not have cards applied
  1749. 08.08 00:40:38.135 TRACE [MLServiceImpl] entering getMlCouponNo(PurchaseEntity). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1750. 08.08 00:40:38.135 TRACE [MLServiceImpl] leaving getMlCouponNo(PurchaseEntity). The receipt does not have cards applied
  1751. 08.08 00:40:38.139 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  1752. 08.08 00:40:38.139 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  1753. 08.08 00:40:38.148 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  1754. 08.08 00:40:38.149 TRACE [LoyPluginEmulator] entering doDiscount(Receipt). The argument is: ru.crystals.api.commons.ReceiptPurchaseWrapper@12993c1
  1755. 08.08 00:40:38.149 TRACE [LoyPluginEmulator] entering readProperties(IntegrationProperties, Logger)
  1756. 08.08 00:40:38.149 TRACE [LoyPluginEmulator] getUrlProperty: the "secondary.calc.url" is not set
  1757. 08.08 00:40:38.149 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, cardProcessingId='null'}; it took 0 [ms]
  1758. 08.08 00:40:38.150 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: "02800"; qnty: 1000; sum: 26227; min-sum: 0; discountable: true], emul-pos [no: 2; marking: "00310"; qnty: 1000; sum: 292; min-sum: 0; discountable: true], emul-pos [no: 3; marking: "08496"; qnty: 1000; sum: 113145; min-sum: 0; discountable: true], emul-pos [no: 4; marking: "09246"; qnty: 1000; sum: 125469; min-sum: 0; discountable: true], emul-pos [no: 5; marking: "02021"; qnty: 1000; sum: 27683; min-sum: 0; discountable: true], emul-pos [no: 6; marking: "01112"; qnty: 1000; sum: 15866; min-sum: 0; discountable: true], emul-pos [no: 7; marking: "08044"; qnty: 1000; sum: 109843; min-sum: 0; discountable: true], emul-pos [no: 8; marking: "07241"; qnty: 1000; sum: 92969; min-sum: 0; discountable: true], emul-pos [no: 9; marking: "06310"; qnty: 1000; sum: 78292; min-sum: 0; discountable: true], emul-pos [no: 10; marking: "04902"; qnty: 1000; sum: 54840; min-sum: 0; discountable: true]]]
  1759. 08.08 00:40:38.191 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  1760. 08.08 00:40:38.200 TRACE [LoyPluginEmulator] leaving makeCalcCalls(List, EmulatorReceipt). The result is: emul-loy-result [discounts: []; limit: null; taken-into-account: null]; it took 51 [ms]
  1761. 08.08 00:40:38.200 TRACE [LoyPluginEmulator] leaving doDiscount(Receipt). The result is: LoyaltyResult{discounts=null, bonusWriteOffsLimits=null, bonusesTakenIntoAccount=null, bonusAccrualResults=null, printDocuments=null, messagesToCashier=null, extendedAttributeMap=null}; it took 51 [ms]
  1762. 08.08 00:40:38.200 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1763. Quantity 1000
  1764. Position sum 262.27
  1765. Value 0
  1766. Min price 0.00
  1767. 08.08 00:40:38.200 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1768. 08.08 00:40:38.200 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1769. Quantity 1000
  1770. Position sum 2.92
  1771. Value 0
  1772. Min price 0.00
  1773. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1774. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1775. Quantity 1000
  1776. Position sum 1131.45
  1777. Value 0
  1778. Min price 0.00
  1779. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1780. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1781. Quantity 1000
  1782. Position sum 1254.69
  1783. Value 0
  1784. Min price 0.00
  1785. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1786. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1787. Quantity 1000
  1788. Position sum 276.83
  1789. Value 0
  1790. Min price 0.00
  1791. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1792. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1793. Quantity 1000
  1794. Position sum 158.66
  1795. Value 0
  1796. Min price 0.00
  1797. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1798. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1799. Quantity 1000
  1800. Position sum 1098.43
  1801. Value 0
  1802. Min price 0.00
  1803. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1804. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1805. Quantity 1000
  1806. Position sum 929.69
  1807. Value 0
  1808. Min price 0.00
  1809. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1810. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1811. Quantity 1000
  1812. Position sum 782.92
  1813. Value 0
  1814. Min price 0.00
  1815. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1816. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Checking MRP restrictions
  1817. Quantity 1000
  1818. Position sum 548.40
  1819. Value 0
  1820. Min price 0.00
  1821. 08.08 00:40:38.201 INFO  [LoyaltyResultSanityChecker] Unable to check MRP restriction: no MRP provided
  1822. 08.08 00:40:38.205 TRACE [MLServiceImpl] entering getMlCardNo(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1823. 08.08 00:40:38.205 TRACE [MLServiceImpl] leaving getMlCardNo(Purchase). The receipt does not have cards applied
  1824. 08.08 00:40:38.205 TRACE [MLServiceImpl] entering getMlCouponNo(PurchaseEntity). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1825. 08.08 00:40:38.205 TRACE [MLServiceImpl] leaving getMlCouponNo(PurchaseEntity). The receipt does not have cards applied
  1826. 08.08 00:40:38.205 TRACE [SCService] entering isEnabled()
  1827. 08.08 00:40:38.205 TRACE [SCService] leaving isEnabled(). the result is: true
  1828. 08.08 00:40:38.205 TRACE [SCService] entering calcDiscount(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  1829. 08.08 00:40:38.209 TRACE [SCService] Send request <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1830. <ChequeRequest xmlns="http://smartcheckout.ru/xsd/s10ren.xsd" ChequeType="Soft">
  1831.     <RequestID>1565214019500</RequestID>
  1832.     <DateTime>2019-08-08T00:40:38.209+03:00</DateTime>
  1833.     <POS>61</POS>
  1834.     <Number>1565214019500</Number>
  1835.     <Summ>6446.26</Summ>
  1836.     <Discount>0.000</Discount>
  1837.     <SummDiscounted>6446.26</SummDiscounted>
  1838.     <Item>
  1839.         <PositionNumber>1</PositionNumber>
  1840.         <Article>02800</Article>
  1841.         <ArticleName>Шоколад малиновый пряный (Испания)</ArticleName>
  1842.         <Price>262.27</Price>
  1843.         <Quantity>1.000</Quantity>
  1844.         <Summ>262.27</Summ>
  1845.         <Discount>0.000</Discount>
  1846.         <SummDiscounted>262.27</SummDiscounted>
  1847.     </Item>
  1848.     <Item>
  1849.         <PositionNumber>2</PositionNumber>
  1850.         <Article>00310</Article>
  1851.         <ArticleName>Шоколад яблочный терпкий (Россия)</ArticleName>
  1852.         <Price>2.92</Price>
  1853.         <Quantity>1.000</Quantity>
  1854.         <Summ>2.92</Summ>
  1855.         <Discount>0.000</Discount>
  1856.         <SummDiscounted>2.92</SummDiscounted>
  1857.     </Item>
  1858.     <Item>
  1859.         <PositionNumber>3</PositionNumber>
  1860.         <Article>08496</Article>
  1861.         <ArticleName>Напиток вишневый густой (Китай)</ArticleName>
  1862.         <Price>1131.45</Price>
  1863.         <Quantity>1.000</Quantity>
  1864.         <Summ>1131.45</Summ>
  1865.         <Discount>0.000</Discount>
  1866.         <SummDiscounted>1131.45</SummDiscounted>
  1867.     </Item>
  1868.     <Item>
  1869.         <PositionNumber>4</PositionNumber>
  1870.         <Article>09246</Article>
  1871.         <ArticleName>Напиток клубничный соленый (Бельгия)</ArticleName>
  1872.         <Price>1254.69</Price>
  1873.         <Quantity>1.000</Quantity>
  1874.         <Summ>1254.69</Summ>
  1875.         <Discount>0.000</Discount>
  1876.         <SummDiscounted>1254.69</SummDiscounted>
  1877.     </Item>
  1878.     <Item>
  1879.         <PositionNumber>5</PositionNumber>
  1880.         <Article>02021</Article>
  1881.         <ArticleName>Кефир виноградный сладкий (Испания)</ArticleName>
  1882.         <Price>276.83</Price>
  1883.         <Quantity>1.000</Quantity>
  1884.         <Summ>276.83</Summ>
  1885.         <Discount>0.000</Discount>
  1886.         <SummDiscounted>276.83</SummDiscounted>
  1887.     </Item>
  1888.     <Item>
  1889.         <PositionNumber>6</PositionNumber>
  1890.         <Article>01112</Article>
  1891.         <ArticleName>Йогурт яблочный кислый (Израиль)</ArticleName>
  1892.         <Price>158.66</Price>
  1893.         <Quantity>1.000</Quantity>
  1894.         <Summ>158.66</Summ>
  1895.         <Discount>0.000</Discount>
  1896.         <SummDiscounted>158.66</SummDiscounted>
  1897.     </Item>
  1898.     <Item>
  1899.         <PositionNumber>7</PositionNumber>
  1900.         <Article>08044</Article>
  1901.         <ArticleName>Хлеб клубничный сладкий (Китай)</ArticleName>
  1902.         <Price>1098.43</Price>
  1903.         <Quantity>1.000</Quantity>
  1904.         <Summ>1098.43</Summ>
  1905.         <Discount>0.000</Discount>
  1906.         <SummDiscounted>1098.43</SummDiscounted>
  1907.     </Item>
  1908.     <Item>
  1909.         <PositionNumber>8</PositionNumber>
  1910.         <Article>07241</Article>
  1911.         <ArticleName>Кефир клубничный соленый (Франция)</ArticleName>
  1912.         <Price>929.69</Price>
  1913.         <Quantity>1.000</Quantity>
  1914.         <Summ>929.69</Summ>
  1915.         <Discount>0.000</Discount>
  1916.         <SummDiscounted>929.69</SummDiscounted>
  1917.     </Item>
  1918.     <Item>
  1919.         <PositionNumber>9</PositionNumber>
  1920.         <Article>06310</Article>
  1921.         <ArticleName>Шоколад яблочный терпкий (Италия)</ArticleName>
  1922.         <Price>782.92</Price>
  1923.         <Quantity>1.000</Quantity>
  1924.         <Summ>782.92</Summ>
  1925.         <Discount>0.000</Discount>
  1926.         <SummDiscounted>782.92</SummDiscounted>
  1927.     </Item>
  1928.     <Item>
  1929.         <PositionNumber>10</PositionNumber>
  1930.         <Article>04902</Article>
  1931.         <ArticleName>Йогурт малиновый горький (Великобритания)</ArticleName>
  1932.         <Price>548.40</Price>
  1933.         <Quantity>1.000</Quantity>
  1934.         <Summ>548.40</Summ>
  1935.         <Discount>0.000</Discount>
  1936.         <SummDiscounted>548.40</SummDiscounted>
  1937.     </Item>
  1938. </ChequeRequest>
  1939.  
  1940. 08.08 00:40:38.210 TRACE [SCService] entering getServices()
  1941. 08.08 00:40:38.210 TRACE [SCService] getting services (IN MEMORY)
  1942. 08.08 00:40:38.210 TRACE [SCService] leaving getServices(). The result size is: 2
  1943. 08.08 00:40:38.260 TRACE [SCService] Received response: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
  1944. <ChequeRequestResponce xmlns="http://smartcheckout.ru/xsd/s10ren.xsd">
  1945.     <RequestID>1565214019500</RequestID>
  1946.     <Processed>2019-08-08T00:40:38.217+03:00</Processed>
  1947.     <ReturnCode>0</ReturnCode>
  1948.     <CashierMessageTO>0</CashierMessageTO>
  1949.     <Summ>6446.26</Summ>
  1950.     <Discount>0.000</Discount>
  1951.     <SummDiscounted>6446.26</SummDiscounted>
  1952.     <Item>
  1953.         <PositionNumber>1</PositionNumber>
  1954.         <Article>02800</Article>
  1955.         <ArticleName>Шоколад малиновый пряный (Испания)</ArticleName>
  1956.         <Price>262.27</Price>
  1957.         <MinPrice>0</MinPrice>
  1958.         <Quantity>1.000</Quantity>
  1959.         <Summ>262.27</Summ>
  1960.         <Discount>0.000</Discount>
  1961.         <SummDiscounted>262.27</SummDiscounted>
  1962.     </Item>
  1963.     <Item>
  1964.         <PositionNumber>2</PositionNumber>
  1965.         <Article>00310</Article>
  1966.         <ArticleName>Шоколад яблочный терпкий (Россия)</ArticleName>
  1967.         <Price>2.92</Price>
  1968.         <MinPrice>0</MinPrice>
  1969.         <Quantity>1.000</Quantity>
  1970.         <Summ>2.92</Summ>
  1971.         <Discount>0.000</Discount>
  1972.         <SummDiscounted>2.92</SummDiscounted>
  1973.     </Item>
  1974.     <Item>
  1975.         <PositionNumber>3</PositionNumber>
  1976.         <Article>08496</Article>
  1977.         <ArticleName>Напиток вишневый густой (Китай)</ArticleName>
  1978.         <Price>1131.45</Price>
  1979.         <MinPrice>0</MinPrice>
  1980.         <Quantity>1.000</Quantity>
  1981.         <Summ>1131.45</Summ>
  1982.         <Discount>0.000</Discount>
  1983.         <SummDiscounted>1131.45</SummDiscounted>
  1984.     </Item>
  1985.     <Item>
  1986.         <PositionNumber>4</PositionNumber>
  1987.         <Article>09246</Article>
  1988.         <ArticleName>Напиток клубничный соленый (Бельгия)</ArticleName>
  1989.         <Price>1254.69</Price>
  1990.         <MinPrice>0</MinPrice>
  1991.         <Quantity>1.000</Quantity>
  1992.         <Summ>1254.69</Summ>
  1993.         <Discount>0.000</Discount>
  1994.         <SummDiscounted>1254.69</SummDiscounted>
  1995.     </Item>
  1996.     <Item>
  1997.         <PositionNumber>5</PositionNumber>
  1998.         <Article>02021</Article>
  1999.         <ArticleName>Кефир виноградный сладкий (Испания)</ArticleName>
  2000.         <Price>276.83</Price>
  2001.         <MinPrice>0</MinPrice>
  2002.         <Quantity>1.000</Quantity>
  2003.         <Summ>276.83</Summ>
  2004.         <Discount>0.000</Discount>
  2005.         <SummDiscounted>276.83</SummDiscounted>
  2006.     </Item>
  2007.     <Item>
  2008.         <PositionNumber>6</PositionNumber>
  2009.         <Article>01112</Article>
  2010.         <ArticleName>Йогурт яблочный кислый (Израиль)</ArticleName>
  2011.         <Price>158.66</Price>
  2012.         <MinPrice>0</MinPrice>
  2013.         <Quantity>1.000</Quantity>
  2014.         <Summ>158.66</Summ>
  2015.         <Discount>0.000</Discount>
  2016.         <SummDiscounted>158.66</SummDiscounted>
  2017.     </Item>
  2018.     <Item>
  2019.         <PositionNumber>7</PositionNumber>
  2020.         <Article>08044</Article>
  2021.         <ArticleName>Хлеб клубничный сладкий (Китай)</ArticleName>
  2022.         <Price>1098.43</Price>
  2023.         <MinPrice>0</MinPrice>
  2024.         <Quantity>1.000</Quantity>
  2025.         <Summ>1098.43</Summ>
  2026.         <Discount>0.000</Discount>
  2027.         <SummDiscounted>1098.43</SummDiscounted>
  2028.     </Item>
  2029.     <Item>
  2030.         <PositionNumber>8</PositionNumber>
  2031.         <Article>07241</Article>
  2032.         <ArticleName>Кефир клубничный соленый (Франция)</ArticleName>
  2033.         <Price>929.69</Price>
  2034.         <MinPrice>0</MinPrice>
  2035.         <Quantity>1.000</Quantity>
  2036.         <Summ>929.69</Summ>
  2037.         <Discount>0.000</Discount>
  2038.         <SummDiscounted>929.69</SummDiscounted>
  2039.     </Item>
  2040.     <Item>
  2041.         <PositionNumber>9</PositionNumber>
  2042.         <Article>06310</Article>
  2043.         <ArticleName>Шоколад яблочный терпкий (Италия)</ArticleName>
  2044.         <Price>782.92</Price>
  2045.         <MinPrice>0</MinPrice>
  2046.         <Quantity>1.000</Quantity>
  2047.         <Summ>782.92</Summ>
  2048.         <Discount>0.000</Discount>
  2049.         <SummDiscounted>782.92</SummDiscounted>
  2050.     </Item>
  2051.     <Item>
  2052.         <PositionNumber>10</PositionNumber>
  2053.         <Article>04902</Article>
  2054.         <ArticleName>Йогурт малиновый горький (Великобритания)</ArticleName>
  2055.         <Price>548.40</Price>
  2056.         <MinPrice>0</MinPrice>
  2057.         <Quantity>1.000</Quantity>
  2058.         <Summ>548.40</Summ>
  2059.         <Discount>0.000</Discount>
  2060.         <SummDiscounted>548.40</SummDiscounted>
  2061.     </Item>
  2062. </ChequeRequestResponce>
  2063.  
  2064. 08.08 00:40:38.260 TRACE [SCReceiptConverter] ml discounts: {position-key [marking: 01112; original-price: 15866]=0, position-key [marking: 09246; original-price: 125469]=0, position-key [marking: 02021; original-price: 27683]=0, position-key [marking: 00310; original-price: 292]=0, position-key [marking: 08044; original-price: 109843]=0, position-key [marking: 07241; original-price: 92969]=0, position-key [marking: 02800; original-price: 26227]=0, position-key [marking: 08496; original-price: 113145]=0, position-key [marking: 06310; original-price: 78292]=0, position-key [marking: 04902; original-price: 54840]=0}
  2065. 08.08 00:40:38.260 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 01112; original-price: 15866]]: SC discount value is: 0
  2066. 08.08 00:40:38.260 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 09246; original-price: 125469]]: SC discount value is: 0
  2067. 08.08 00:40:38.260 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 02021; original-price: 27683]]: SC discount value is: 0
  2068. 08.08 00:40:38.260 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 00310; original-price: 292]]: SC discount value is: 0
  2069. 08.08 00:40:38.261 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 08044; original-price: 109843]]: SC discount value is: 0
  2070. 08.08 00:40:38.261 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 07241; original-price: 92969]]: SC discount value is: 0
  2071. 08.08 00:40:38.261 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 02800; original-price: 26227]]: SC discount value is: 0
  2072. 08.08 00:40:38.261 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 08496; original-price: 113145]]: SC discount value is: 0
  2073. 08.08 00:40:38.261 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 06310; original-price: 78292]]: SC discount value is: 0
  2074. 08.08 00:40:38.261 TRACE [SCReceiptConverter] it was inferred that no SC POS discounts were given on position [key: position-key [marking: 04902; original-price: 54840]]: SC discount value is: 0
  2075. 08.08 00:40:38.261 TRACE [SCService] leaving calcDiscount(Purchase). The result is: Purchase{number=null, dateCreate=null, checkSum=644626, operationType=null, discountValueTotal=0}; it took 56 [ms]
  2076. 08.08 00:40:38.262 DEBUG [LoymaxUtils] Loymax request:
  2077. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLRequest><Version>3.2</Version><CancelPurchases><CancelPurchaseRequest PurchaseID="71710611565214034960" OperationID="9f2b7914aec44adaa3d5e7b0905ea764" OperationDate="2019-08-08T00:40:38.261+03:00" ElementID="1"/></CancelPurchases></XMLRequest>
  2078.  
  2079. 08.08 00:40:38.280 DEBUG [LoymaxUtils] Loymax response:
  2080. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLResponse><ErrorCode>0</ErrorCode><CancelPurchases><CancelPurchaseResponse PurchaseID="71710611565214034960" OperationID="9f2b7914aec44adaa3d5e7b0905ea764" OperationDate="2019-08-08T00:40:38.261+03:00" ErrorCode="0"/></CancelPurchases></XMLResponse>
  2081.  
  2082. 08.08 00:40:38.298 DEBUG [LoymaxUtils] Loymax request:
  2083. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLRequest><Version>3.2</Version><Calculates><CalculateRequest PurchaseID="71710611565214038280" OperationID="7be6edb912a34ab5b2ce21ac52fa913a" OperationDate="2019-08-08T00:40:38.280+03:00" ElementID="1"><Cheque ChequeDate="2019-08-08T00:40:19.500+03:00"><ChequeLine PosID="17132" Amount="262.27" Name="Шоколад малиновый пряный (Испания)" GoodsId="02800" Price="262.27" Quantity="1.000"/><ChequeLine PosID="17133" Amount="2.92" Name="Шоколад яблочный терпкий (Россия)" GoodsId="00310" Price="2.92" Quantity="1.000"/><ChequeLine PosID="17134" Amount="1131.45" Name="Напиток вишневый густой (Китай)" GoodsId="08496" Price="1131.45" Quantity="1.000"/><ChequeLine PosID="17135" Amount="1254.69" Name="Напиток клубничный соленый (Бельгия)" GoodsId="09246" Price="1254.69" Quantity="1.000"/><ChequeLine PosID="17136" Amount="276.83" Name="Кефир виноградный сладкий (Испания)" GoodsId="02021" Price="276.83" Quantity="1.000"/><ChequeLine PosID="17137" Amount="158.66" Name="Йогурт яблочный кислый (Израиль)" GoodsId="01112" Price="158.66" Quantity="1.000"/><ChequeLine PosID="17138" Amount="1098.43" Name="Хлеб клубничный сладкий (Китай)" GoodsId="08044" Price="1098.43" Quantity="1.000"/><ChequeLine PosID="17139" Amount="929.69" Name="Кефир клубничный соленый (Франция)" GoodsId="07241" Price="929.69" Quantity="1.000"/><ChequeLine PosID="17240" Amount="782.92" Name="Шоколад яблочный терпкий (Италия)" GoodsId="06310" Price="782.92" Quantity="1.000"/><ChequeLine PosID="17241" Amount="548.40" Name="Йогурт малиновый горький (Великобритания)" GoodsId="04902" Price="548.40" Quantity="1.000"/></Cheque></CalculateRequest></Calculates></XMLRequest>
  2084.  
  2085. 08.08 00:40:38.334 ERROR [ConnectionEmulatorUtils] toString(XmlEmulatorException): the argument is null
  2086. 08.08 00:40:38.349 DEBUG [LoymaxUtils] Loymax response:
  2087. <?xml version="1.0" encoding="UTF-8" standalone="yes"?><XMLResponse><ErrorCode>0</ErrorCode><Calculates><CalculateResponse AvailableAmount="6446.26" AvailableBonusAmount="0" ErrorCode="0"><Cheque ChequeDate="2019-08-08T00:40:19.500+03:00"><ChequeLine PosID="17132" Amount="262.27" Name="Шоколад малиновый пряный (Испания)" GoodsId="02800" Price="262.27" Quantity="1.000" Discount="0"/><ChequeLine PosID="17133" Amount="2.92" Name="Шоколад яблочный терпкий (Россия)" GoodsId="00310" Price="2.92" Quantity="1.000" Discount="0"/><ChequeLine PosID="17134" Amount="1131.45" Name="Напиток вишневый густой (Китай)" GoodsId="08496" Price="1131.45" Quantity="1.000" Discount="0"/><ChequeLine PosID="17135" Amount="1254.69" Name="Напиток клубничный соленый (Бельгия)" GoodsId="09246" Price="1254.69" Quantity="1.000" Discount="0"/><ChequeLine PosID="17136" Amount="276.83" Name="Кефир виноградный сладкий (Испания)" GoodsId="02021" Price="276.83" Quantity="1.000" Discount="0"/><ChequeLine PosID="17137" Amount="158.66" Name="Йогурт яблочный кислый (Израиль)" GoodsId="01112" Price="158.66" Quantity="1.000" Discount="0"/><ChequeLine PosID="17138" Amount="1098.43" Name="Хлеб клубничный сладкий (Китай)" GoodsId="08044" Price="1098.43" Quantity="1.000" Discount="0"/><ChequeLine PosID="17139" Amount="929.69" Name="Кефир клубничный соленый (Франция)" GoodsId="07241" Price="929.69" Quantity="1.000" Discount="0"/><ChequeLine PosID="17240" Amount="782.92" Name="Шоколад яблочный терпкий (Италия)" GoodsId="06310" Price="782.92" Quantity="1.000" Discount="0"/><ChequeLine PosID="17241" Amount="548.40" Name="Йогурт малиновый горький (Великобритания)" GoodsId="04902" Price="548.40" Quantity="1.000" Discount="0"/></Cheque></CalculateResponse></Calculates></XMLResponse>
  2088.  
  2089. 08.08 00:40:38.363 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  2090. 08.08 00:40:38.363 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  2091. 08.08 00:40:38.384 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  2092. 08.08 00:40:38.390 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  2093. 08.08 00:40:38.391 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  2094. 08.08 00:40:38.391 WARN  [AdvancedMessagesActionResult] Calculator returns empty result. Do not generate slips or messages
  2095. 08.08 00:40:38.482 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  2096. 08.08 00:40:38.484 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount start ============
  2097. 08.08 00:40:38.484 INFO  [DoProcessing] GeneralInteractionMethod: MAXIMUM_DISCOUNT
  2098. 08.08 00:40:38.485 INFO  [DoProcessing] ============ LoyalCalculation: doDiscount success ============
  2099. 08.08 00:40:38.516 INFO  [SetApiPluginLoyProvider] Plugin "ru.crystals.loy.plugin.emulator" does not do post discount tuning
  2100. 08.08 00:40:38.517 TRACE [MLServiceImpl] entering getMlCardNo(Purchase). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  2101. 08.08 00:40:38.517 TRACE [MLServiceImpl] leaving getMlCardNo(Purchase). The receipt does not have cards applied
  2102. 08.08 00:40:38.517 TRACE [MLServiceImpl] entering getMlCouponNo(PurchaseEntity). The argument is: Purchase{number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, checkSum=644626, operationType=true, discountValueTotal=0}
  2103. 08.08 00:40:38.517 TRACE [MLServiceImpl] leaving getMlCouponNo(PurchaseEntity). The receipt does not have cards applied
  2104. 08.08 00:40:38.517 INFO  [LoyalServiceImpl] Discount calculation (Purchase #183; Positions: 10
  2105. 08.08 00:40:38.620 INFO  [LoyalBridgeServiceImpl] Total time of discount calculation = 492 ms
  2106. 08.08 00:40:38.621 INFO  [LoyalBridgeServiceImpl] ---------------- end discount calculation ----------------
  2107. 08.08 00:40:38.641 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  2108. 08.08 00:40:38.641 INFO  [TextCustomerDisplayPluginAbstract] **********************
  2109. 08.08 00:40:38.641 INFO  [TextCustomerDisplayPluginAbstract] *Скидка          0.00*
  2110. 08.08 00:40:38.641 INFO  [TextCustomerDisplayPluginAbstract] *Итого        6446.26*
  2111. 08.08 00:40:38.641 INFO  [TextCustomerDisplayPluginAbstract] **********************
  2112. 08.08 00:40:38.641 INFO  [TextCustomerDisplayPluginAbstract]
  2113. 08.08 00:40:38.684 INFO  [SpeedLog] TechProcess discounts processing on cheque with 10 positions [sale] time = 720 ms
  2114. 08.08 00:40:38.687 INFO  [CommonLogger] value = 0
  2115. 08.08 00:40:38.718 TRACE [TechProcessImpl] Start warn divide amount
  2116. 08.08 00:40:38.722 INFO  [TechProcessImpl] goToPayments
  2117. 08.08 00:40:38.724 INFO  [CheckContainer] startPayments() surcharge = 644626
  2118. 08.08 00:40:38.730 INFO  [CheckContainer] isPaymentComplete = false
  2119. 08.08 00:40:38.730 INFO  [CheckContainer] prevState = SELECT_PAYMENT_TYPE
  2120. 08.08 00:40:38.730 INFO  [CheckContainer] paid = 0
  2121. 08.08 00:40:38.730 INFO  [CheckContainer] surcharge = 644626
  2122. 08.08 00:40:38.730 INFO  [CheckContainer] getPaymentFiscalizeError = NONE
  2123. 08.08 00:40:38.732 INFO  [CheckContainer] Current payment container is ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentPluginAdapter
  2124. 08.08 00:40:38.732 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_SUM, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2125. 08.08 00:40:38.732 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_SUM, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2126. 08.08 00:40:38.736 INFO  [AbstractPaymentModel] Setting payment: PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}
  2127. 08.08 00:40:38.736 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_SUM, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2128. 08.08 00:40:38.736 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_SUM, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=null, sumPayBaseCurrency=null, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2129. 08.08 00:40:38.740 INFO  [CommonLogger] busy = false
  2130. 08.08 00:40:38.740 INFO  [SpeedLog] (SUBTOTAL) time = 0,780;
  2131. 08.08 00:40:38.741 INFO  [CommonLogger] busy = false
  2132. 08.08 00:40:40.212 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_SUM, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=644626, sumPayBaseCurrency=644626, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2133. 08.08 00:40:40.212 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_LAST_4_DIGITS, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=644626, sumPayBaseCurrency=644626, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2134. 08.08 00:40:40.213 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  2135. 08.08 00:40:41.217 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_LAST_4_DIGITS, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=644626, sumPayBaseCurrency=644626, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2136. 08.08 00:40:41.217 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_AUTH_CODE, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=644626, sumPayBaseCurrency=644626, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2137. 08.08 00:40:41.218 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  2138. 08.08 00:40:42.624 INFO  [ExtBankTerminalPaymentView] lastEvent: PaymentModelChangedEvent{state=ENTER_AUTH_CODE, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=644626, sumPayBaseCurrency=644626, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2139. 08.08 00:40:42.624 INFO  [ExtBankTerminalPaymentView] event: PaymentModelChangedEvent{state=ENTER_RECEIPT_NUMBER, payment=PaymentEntity{, number=null, dateCreate=null, dateCommit=null, sumPay=644626, sumPayBaseCurrency=644626, purchase=null, paymentType='ExternalBankTerminalPaymentEntity', baseCurrency='null', paymentStatus=null, currency='null', successProcessed=true, originalPaymentNumber=null}, info=ExtBankTerminalPaymentInfo{lastDigits='1234', checkNumber=123456, authCode='123456'}}
  2140. 08.08 00:40:42.625 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  2141. 08.08 00:40:44.031 INFO  [CommonLogger] doProcessPayment() in class ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentPluginAdapter
  2142. 08.08 00:40:44.031 INFO  [TechProcessImpl] addPayment ExternalBankTerminalPaymentEntity 644626
  2143. 08.08 00:40:44.209 WARN  [PrismaBridgeImpl] Can't send [add payment] prisma event, position or purchase is empty
  2144. 08.08 00:40:44.209 TRACE [TechProcessEventsImpl] entering purchaseChangedAtPaymentsStage(PurchaseEntity, List). The arguments are: purchase [PurchaseEntity [id=16884, number=null, dateCreate=Thu Aug 08 00:40:19 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]], notifications [[]]
  2145. 08.08 00:40:44.226 INFO  [CommonLogger] value = 0
  2146. 08.08 00:40:44.238 TRACE [TechProcessEventsImpl] leaving purchaseChangedAtPaymentsStage(PurchaseEntity, List). It took 29 [ms]
  2147. 08.08 00:40:44.239 WARN  [PrismaBridgeImpl] Can't send [add payment complete] prisma event, position or change is empty
  2148. 08.08 00:40:44.240 INFO  [TextCustomerDisplayPluginAbstract] Screen updated:
  2149. 08.08 00:40:44.240 INFO  [TextCustomerDisplayPluginAbstract] **********************
  2150. 08.08 00:40:44.240 INFO  [TextCustomerDisplayPluginAbstract] *Оплачено     6446.26*
  2151. 08.08 00:40:44.240 INFO  [TextCustomerDisplayPluginAbstract] *Cдача           0.00*
  2152. 08.08 00:40:44.240 INFO  [TextCustomerDisplayPluginAbstract] **********************
  2153. 08.08 00:40:44.240 INFO  [TextCustomerDisplayPluginAbstract]
  2154. 08.08 00:40:44.249 INFO  [TechProcessShift] fiscalizeCheck PurchaseEntity [id=16884, number=null, dateCreate=Thu Aug 08 00:40:19 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  2155. 08.08 00:40:44.607 INFO  [FiscalPrinter] getLastKpk
  2156. 08.08 00:40:44.608 INFO  [FiscalPrinter] LastKpk = 644
  2157. 08.08 00:40:44.809 WARN  [SetApiPluginLoyProvider] No LoyaltyPlugin "ru.crystals.loy.plugin.emulator" found for purchase id 16884
  2158. 08.08 00:40:44.809 INFO  [FiscalPrinter] printCheck
  2159. 08.08 00:40:44.809 INFO  [FiscalPrinter] getLastKpk
  2160. 08.08 00:40:44.809 INFO  [FiscalPrinter] LastKpk = 644
  2161. 08.08 00:40:44.809 INFO  [FiscalPrinter] Fiscal interrupt: null
  2162. 08.08 00:40:44.810 INFO  [FiscalPrinter] Get document template /mnt/sda1/tce/storage/crystal-cash/modules/fiscalPrinter/templates/check-sale.xml
  2163. 08.08 00:40:44.810 INFO  [DocumentTemplate] =====logo=====
  2164. 08.08 00:40:44.810 INFO  [DocumentTemplate] content: null
  2165. 08.08 00:40:44.814 INFO  [DocumentTemplate] =====header=====
  2166. 08.08 00:40:44.814 INFO  [DocumentTemplate]                    jr. name                   ||NORMAL
  2167. 08.08 00:40:44.815 INFO  [DocumentTemplate]          199100, Spb, Savushkina, 112         ||NORMAL
  2168. 08.08 00:40:44.815 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  2169. 08.08 00:40:44.815 INFO  [DocumentTemplate] ЗВД.N:00000717161         ФН:      72afb605-7a||NORMAL
  2170. 08.08 00:40:44.815 INFO  [DocumentTemplate] РЕГ.N:NFM.7171.61.0.156519ИНН:     7802781104 ||NORMAL
  2171. 08.08 00:40:44.815 INFO  [DocumentTemplate] 01    Администраторов Адми     КАССА: 61 ОТД01||NORMAL
  2172. 08.08 00:40:44.815 INFO  [DocumentTemplate]   ЧЕК НА ПРОДАЖУ N:          183            ||NORMAL
  2173. 08.08 00:40:44.815 INFO  [DocumentTemplate]                                 СМЕНА N:      ||NORMAL
  2174. 08.08 00:40:44.815 INFO  [DocumentTemplate] =====text=====
  2175. 08.08 00:40:44.839 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  2176. 08.08 00:40:44.839 INFO  [DocumentTemplate] Кассовый чек (ПРИХОД)                         ||NORMAL
  2177. 08.08 00:40:44.839 INFO  [DocumentTemplate]                *ПРОДАЖА ТОВАРА*               ||NORMAL
  2178. 08.08 00:40:44.844 INFO  [DocumentTemplate] =====positionSectionWithGoodSets=====
  2179. 08.08 00:40:44.849 INFO  [DocumentTemplate] ------------------------------------------||NORMAL
  2180. 08.08 00:40:44.849 INFO  [DocumentTemplate] Шоколад малиновый п   262.27     *1    =262.27||SMALL
  2181. 08.08 00:40:44.849 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2182. 08.08 00:40:44.849 INFO  [DocumentTemplate] Шоколад яблочный те     2.92     *1      =2.92||SMALL
  2183. 08.08 00:40:44.849 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2184. 08.08 00:40:44.849 INFO  [DocumentTemplate] Напиток вишневый гу  1131.45     *1   =1131.45||SMALL
  2185. 08.08 00:40:44.849 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2186. 08.08 00:40:44.849 INFO  [DocumentTemplate] Напиток клубничный   1254.69     *1   =1254.69||SMALL
  2187. 08.08 00:40:44.849 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2188. 08.08 00:40:44.849 INFO  [DocumentTemplate] Кефир виноградный с   276.83     *1    =276.83||SMALL
  2189. 08.08 00:40:44.852 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2190. 08.08 00:40:44.852 INFO  [DocumentTemplate] Йогурт яблочный кис   158.66     *1    =158.66||SMALL
  2191. 08.08 00:40:44.852 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2192. 08.08 00:40:44.852 INFO  [DocumentTemplate] Хлеб клубничный сла  1098.43     *1   =1098.43||SMALL
  2193. 08.08 00:40:44.852 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2194. 08.08 00:40:44.852 INFO  [DocumentTemplate] Кефир клубничный со   929.69     *1    =929.69||SMALL
  2195. 08.08 00:40:44.852 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2196. 08.08 00:40:44.852 INFO  [DocumentTemplate] Шоколад яблочный те   782.92     *1    =782.92||SMALL
  2197. 08.08 00:40:44.852 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2198. 08.08 00:40:44.852 INFO  [DocumentTemplate] Йогурт малиновый го   548.40     *1    =548.40||SMALL
  2199. 08.08 00:40:44.852 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2200. 08.08 00:40:44.852 INFO  [DocumentTemplate] ------------------------------------------||NORMAL
  2201. 08.08 00:40:44.853 INFO  [DocumentTemplate] =====payment=====
  2202. 08.08 00:40:44.853 INFO  [DocumentTemplate] ПОДИТОГ                               =6446.26||SMALL
  2203. 08.08 00:40:44.853 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  2204. 08.08 00:40:44.853 INFO  [DocumentTemplate]          ИТОГО к ОПЛАТЕ         =6446.26      ||NORMAL
  2205. 08.08 00:40:44.853 INFO  [DocumentTemplate] ВНЕШНИЙ БАНКОВСКИЙ ТЕРМ         =6446.26      ||NORMAL
  2206. 08.08 00:40:44.853 INFO  [DocumentTemplate] =====text=====
  2207. 08.08 00:40:44.853 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  2208. 08.08 00:40:44.854 INFO  [DocumentTemplate]  ||NORMAL
  2209. 08.08 00:40:44.854 INFO  [DocumentTemplate]                *ПРОДАЖА ТОВАРА*               ||NORMAL
  2210. 08.08 00:40:44.854 INFO  [DocumentTemplate]                                               ||NORMAL
  2211. 08.08 00:40:44.854 INFO  [DocumentTemplate]              СПАСИБО ЗА ПОКУПКУ!              ||NORMAL
  2212. 08.08 00:40:44.854 INFO  [DocumentTemplate]                                               ||NORMAL
  2213. 08.08 00:40:44.854 INFO  [DocumentTemplate]                                               ||NORMAL
  2214. 08.08 00:40:44.854 INFO  [DocumentTemplate] =====text=====
  2215. 08.08 00:40:44.858 INFO  [DocumentTemplate] =====bonuses=====
  2216. 08.08 00:40:44.858 INFO  [DocumentTemplate] =====fiscal=====
  2217. 08.08 00:40:44.858 INFO  [DocumentTemplate]                                            ||NORMAL
  2218. 08.08 00:40:44.858 INFO  [DocumentTemplate]        Вся информация на www.lenta.com     ||NORMAL
  2219. 08.08 00:40:44.858 INFO  [DocumentTemplate]           и по тел. 8-800-700-4111         ||NORMAL
  2220. 08.08 00:40:44.858 INFO  [DocumentTemplate]          звонок по России бесплатный       ||NORMAL
  2221. 08.08 00:40:44.858 INFO  [DocumentTemplate] =====cut=====
  2222. 08.08 00:40:44.858 INFO  [DocumentTemplate] content: null
  2223. 08.08 00:40:45.089 ERROR [FiscalPrinter]
  2224. ru.crystals.pos.fiscalprinter.exception.FiscalPrinterException:
  2225.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.FiscalPrinterEmulatorData.throwManualException(FiscalPrinterEmulatorData.java:1348)
  2226.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.FiscalPrinterEmulatorData.closeCheck(FiscalPrinterEmulatorData.java:829)
  2227.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.closeDocument(AbstractFiscalPrinterEmulator.java:845)
  2228.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printCheckByTemplate(AbstractFiscalPrinterEmulator.java:802)
  2229.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printDocumentByTemplate(AbstractFiscalPrinterEmulator.java:602)
  2230.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printDocument(AbstractFiscalPrinterEmulator.java:550)
  2231.     at ru.crystals.pos.fiscalprinter.templates.DocumentTemplate.printByPlugin(DocumentTemplate.java:114)
  2232.     at ru.crystals.pos.fiscalprinter.templates.DocumentTemplate.printDocument(DocumentTemplate.java:82)
  2233.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printSaleOrReturnCheck(FiscalPrinterImpl.java:861)
  2234.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printCheck(FiscalPrinterImpl.java:795)
  2235.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1767)
  2236.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  2237.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:700)
  2238.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  2239.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  2240.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  2241.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  2242.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  2243.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  2244.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  2245.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  2246.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  2247.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processPayWithExtBankTerminal(ExtBankTerminalPaymentController.java:79)
  2248.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processReceiptNumberEntered(ExtBankTerminalPaymentController.java:50)
  2249.     at ru.crystals.pos.visualization.payments.externalbankterminal.forms.ExtBankTerminalPaymentEnterReceiptNumberForm.keyPressedNew(ExtBankTerminalPaymentEnterReceiptNumberForm.java:73)
  2250.     at ru.crystals.pos.visualization.payments.common.AbstractPaymentForm$1.keyPressedNew(AbstractPaymentForm.java:78)
  2251.     at ru.crystals.pos.CashEventSource.sendNewKey(CashEventSource.java:149)
  2252.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:137)
  2253.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  2254.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  2255.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  2256.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  2257.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  2258.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  2259.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  2260.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  2261.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  2262.     at java.lang.Thread.run(Thread.java:745)
  2263. 08.08 00:40:45.092 INFO  [AbstractFiscalPrinterEmulator] Can't remove entity from control tape
  2264. 08.08 00:40:45.092 ERROR [FiscalPrinter]
  2265. ru.crystals.pos.fiscalprinter.exception.FiscalPrinterException:
  2266.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.FiscalPrinterEmulatorData.throwManualException(FiscalPrinterEmulatorData.java:1348)
  2267.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.FiscalPrinterEmulatorData.closeCheck(FiscalPrinterEmulatorData.java:829)
  2268.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.closeDocument(AbstractFiscalPrinterEmulator.java:845)
  2269.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printCheckByTemplate(AbstractFiscalPrinterEmulator.java:802)
  2270.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printDocumentByTemplate(AbstractFiscalPrinterEmulator.java:602)
  2271.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printDocument(AbstractFiscalPrinterEmulator.java:550)
  2272.     at ru.crystals.pos.fiscalprinter.templates.DocumentTemplate.printByPlugin(DocumentTemplate.java:114)
  2273.     at ru.crystals.pos.fiscalprinter.templates.DocumentTemplate.printDocument(DocumentTemplate.java:82)
  2274.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printSaleOrReturnCheck(FiscalPrinterImpl.java:861)
  2275.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printCheck(FiscalPrinterImpl.java:795)
  2276.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1767)
  2277.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  2278.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:700)
  2279.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  2280.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  2281.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  2282.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  2283.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  2284.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  2285.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  2286.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  2287.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  2288.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processPayWithExtBankTerminal(ExtBankTerminalPaymentController.java:79)
  2289.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processReceiptNumberEntered(ExtBankTerminalPaymentController.java:50)
  2290.     at ru.crystals.pos.visualization.payments.externalbankterminal.forms.ExtBankTerminalPaymentEnterReceiptNumberForm.keyPressedNew(ExtBankTerminalPaymentEnterReceiptNumberForm.java:73)
  2291.     at ru.crystals.pos.visualization.payments.common.AbstractPaymentForm$1.keyPressedNew(AbstractPaymentForm.java:78)
  2292.     at ru.crystals.pos.CashEventSource.sendNewKey(CashEventSource.java:149)
  2293.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:137)
  2294.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  2295.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  2296.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  2297.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  2298.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  2299.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  2300.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  2301.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  2302.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  2303.     at java.lang.Thread.run(Thread.java:745)
  2304. 08.08 00:40:45.092 INFO  [FiscalPrinter] Fiscal interrupt: null
  2305. 08.08 00:40:45.092 ERROR [FiscalPrinter] Print interrupted:
  2306. ru.crystals.pos.fiscalprinter.exception.FiscalPrinterException:
  2307.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.FiscalPrinterEmulatorData.throwManualException(FiscalPrinterEmulatorData.java:1348)
  2308.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.FiscalPrinterEmulatorData.closeCheck(FiscalPrinterEmulatorData.java:829)
  2309.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.closeDocument(AbstractFiscalPrinterEmulator.java:845)
  2310.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printCheckByTemplate(AbstractFiscalPrinterEmulator.java:802)
  2311.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printDocumentByTemplate(AbstractFiscalPrinterEmulator.java:602)
  2312.     at ru.crystals.pos.fiscalprinter.nonfiscalmode.emulator.AbstractFiscalPrinterEmulator.printDocument(AbstractFiscalPrinterEmulator.java:550)
  2313.     at ru.crystals.pos.fiscalprinter.templates.DocumentTemplate.printByPlugin(DocumentTemplate.java:114)
  2314.     at ru.crystals.pos.fiscalprinter.templates.DocumentTemplate.printDocument(DocumentTemplate.java:82)
  2315.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printSaleOrReturnCheck(FiscalPrinterImpl.java:861)
  2316.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printCheck(FiscalPrinterImpl.java:795)
  2317.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1767)
  2318.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  2319.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:700)
  2320.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  2321.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  2322.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  2323.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  2324.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  2325.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  2326.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  2327.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  2328.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  2329.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processPayWithExtBankTerminal(ExtBankTerminalPaymentController.java:79)
  2330.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processReceiptNumberEntered(ExtBankTerminalPaymentController.java:50)
  2331.     at ru.crystals.pos.visualization.payments.externalbankterminal.forms.ExtBankTerminalPaymentEnterReceiptNumberForm.keyPressedNew(ExtBankTerminalPaymentEnterReceiptNumberForm.java:73)
  2332.     at ru.crystals.pos.visualization.payments.common.AbstractPaymentForm$1.keyPressedNew(AbstractPaymentForm.java:78)
  2333.     at ru.crystals.pos.CashEventSource.sendNewKey(CashEventSource.java:149)
  2334.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:137)
  2335.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  2336.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  2337.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  2338.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  2339.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  2340.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  2341.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  2342.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  2343.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  2344.     at java.lang.Thread.run(Thread.java:745)
  2345. 08.08 00:40:45.095 INFO  [AbstractFiscalPrinterEmulator]  getStatus
  2346. 08.08 00:40:45.095 ERROR [TechProcessShift] Cannot print cheque PurchaseEntity [id=16884, number=183, dateCreate=Thu Aug 08 00:40:19 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  2347. ru.crystals.pos.fiscalprinter.exception.FiscalPrinterException: Закончилась чековая лента. Вставьте чековую ленту, нажмите “Повторить”
  2348.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.processNegativeScript(FiscalPrinterImpl.java:1038)
  2349.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printCheck(FiscalPrinterImpl.java:799)
  2350.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1767)
  2351.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  2352.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:700)
  2353.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  2354.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  2355.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  2356.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  2357.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  2358.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  2359.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  2360.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  2361.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  2362.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processPayWithExtBankTerminal(ExtBankTerminalPaymentController.java:79)
  2363.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processReceiptNumberEntered(ExtBankTerminalPaymentController.java:50)
  2364.     at ru.crystals.pos.visualization.payments.externalbankterminal.forms.ExtBankTerminalPaymentEnterReceiptNumberForm.keyPressedNew(ExtBankTerminalPaymentEnterReceiptNumberForm.java:73)
  2365.     at ru.crystals.pos.visualization.payments.common.AbstractPaymentForm$1.keyPressedNew(AbstractPaymentForm.java:78)
  2366.     at ru.crystals.pos.CashEventSource.sendNewKey(CashEventSource.java:149)
  2367.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:137)
  2368.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  2369.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  2370.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  2371.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  2372.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  2373.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  2374.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  2375.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  2376.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  2377.     at java.lang.Thread.run(Thread.java:745)
  2378. 08.08 00:40:45.107 ERROR [TechProcessShift] Cannot fiscalize the cheque 0
  2379. ru.crystals.pos.fiscalprinter.exception.FiscalPrinterException: Закончилась чековая лента. Вставьте чековую ленту, нажмите “Повторить”
  2380.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.processNegativeScript(FiscalPrinterImpl.java:1038)
  2381.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printCheck(FiscalPrinterImpl.java:799)
  2382.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1767)
  2383.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  2384.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:700)
  2385.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  2386.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  2387.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  2388.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  2389.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  2390.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  2391.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  2392.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  2393.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  2394.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processPayWithExtBankTerminal(ExtBankTerminalPaymentController.java:79)
  2395.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processReceiptNumberEntered(ExtBankTerminalPaymentController.java:50)
  2396.     at ru.crystals.pos.visualization.payments.externalbankterminal.forms.ExtBankTerminalPaymentEnterReceiptNumberForm.keyPressedNew(ExtBankTerminalPaymentEnterReceiptNumberForm.java:73)
  2397.     at ru.crystals.pos.visualization.payments.common.AbstractPaymentForm$1.keyPressedNew(AbstractPaymentForm.java:78)
  2398.     at ru.crystals.pos.CashEventSource.sendNewKey(CashEventSource.java:149)
  2399.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:137)
  2400.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  2401.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  2402.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  2403.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  2404.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  2405.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  2406.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  2407.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  2408.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  2409.     at java.lang.Thread.run(Thread.java:745)
  2410. 08.08 00:40:45.143 ERROR [FiscalizeCheckScenarioImpl] Закончилась чековая лента. Вставьте чековую ленту, нажмите “Повторить”
  2411. ru.crystals.pos.fiscalprinter.exception.FiscalPrinterException: Закончилась чековая лента. Вставьте чековую ленту, нажмите “Повторить”
  2412.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.processNegativeScript(FiscalPrinterImpl.java:1038)
  2413.     at ru.crystals.pos.fiscalprinter.FiscalPrinterImpl.printCheck(FiscalPrinterImpl.java:799)
  2414.     at ru.crystals.pos.techprocess.TechProcessShift.printCheck(TechProcessShift.java:1767)
  2415.     at ru.crystals.pos.techprocess.TechProcessShift.fiscalizeCheck(TechProcessShift.java:1538)
  2416.     at ru.crystals.pos.techprocess.TechProcessShiftProxy.fiscalizeCheck(TechProcessShiftProxy.java:700)
  2417.     at ru.crystals.pos.techprocess.TechProcessImpl.fiscalizeCheck(TechProcessImpl.java:941)
  2418.     at ru.crystals.pos.visualization.check.CheckContainer.paymentComplete(CheckContainer.java:2728)
  2419.     at ru.crystals.pos.visualization.components.MainWindow.paymentComplete(MainWindow.java:845)
  2420.     at ru.crystals.pos.visualization.Factory.eventPaymentComplete(Factory.java:880)
  2421.     at ru.crystals.pos.techprocess.TechProcessImpl.paymentComplete(TechProcessImpl.java:4477)
  2422.     at ru.crystals.pos.check.service.CheckServiceImpl.addPayment(CheckServiceImpl.java:3972)
  2423.     at ru.crystals.pos.techprocess.TechProcessImpl.addPayment(TechProcessImpl.java:3927)
  2424.     at ru.crystals.pos.visualization.payments.PaymentContainer.doProcessPayment(PaymentContainer.java:387)
  2425.     at ru.crystals.pos.visualization.payments.PaymentContainer.processPayment(PaymentContainer.java:347)
  2426.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processPayWithExtBankTerminal(ExtBankTerminalPaymentController.java:79)
  2427.     at ru.crystals.pos.visualization.payments.externalbankterminal.integration.ExtBankTerminalPaymentController.processReceiptNumberEntered(ExtBankTerminalPaymentController.java:50)
  2428.     at ru.crystals.pos.visualization.payments.externalbankterminal.forms.ExtBankTerminalPaymentEnterReceiptNumberForm.keyPressedNew(ExtBankTerminalPaymentEnterReceiptNumberForm.java:73)
  2429.     at ru.crystals.pos.visualization.payments.common.AbstractPaymentForm$1.keyPressedNew(AbstractPaymentForm.java:78)
  2430.     at ru.crystals.pos.CashEventSource.sendNewKey(CashEventSource.java:149)
  2431.     at ru.crystals.pos.CashEventSource.process(CashEventSource.java:137)
  2432.     at ru.crystals.pos.CashEventSource.processEvent(CashEventSource.java:118)
  2433.     at ru.crystals.pos.CashEventSource.run(CashEventSource.java:101)
  2434.     at ru.crystals.pos.InternalCashPoolExecutorImpl.lambda$submit$2(InternalCashPoolExecutorImpl.java:115)
  2435.     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
  2436.     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  2437.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
  2438.     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
  2439.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  2440.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  2441.     at java.lang.Thread.run(Thread.java:745)
  2442. 08.08 00:40:45.151 INFO  [CommonLogger] Show message Закончилась чековая лента. Вставьте чековую ленту, нажмите “Повторить”
  2443. 08.08 00:40:45.177 INFO  [TechProcessImpl] eventControlKey: ControlKey [scanCode=10, command=kbdEnter]
  2444. 08.08 00:40:45.184 INFO  [FiscalPrinter] resetException()
  2445. 08.08 00:40:45.606 INFO  [CommonLogger] ENTER
  2446. 08.08 00:40:45.606 INFO  [CommonLogger] cashException.getErrorType() = FISCAL_ERROR
  2447. 08.08 00:40:45.613 INFO  [TechProcessShift] fiscalizeCheck PurchaseEntity [id=16884, number=null, dateCreate=Thu Aug 08 00:40:19 MSK 2019, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  2448. 08.08 00:40:45.807 WARN  [SetApiPluginLoyProvider] No LoyaltyPlugin "ru.crystals.loy.plugin.emulator" found for purchase id 16884
  2449. 08.08 00:40:45.808 INFO  [FiscalPrinter] printCheck
  2450. 08.08 00:40:45.808 INFO  [FiscalPrinter] getLastKpk
  2451. 08.08 00:40:45.808 INFO  [FiscalPrinter] LastKpk = 644
  2452. 08.08 00:40:45.808 INFO  [FiscalPrinter] Fiscal interrupt: null
  2453. 08.08 00:40:45.808 INFO  [FiscalPrinter] Get document template /mnt/sda1/tce/storage/crystal-cash/modules/fiscalPrinter/templates/check-sale.xml
  2454. 08.08 00:40:45.808 INFO  [DocumentTemplate] =====logo=====
  2455. 08.08 00:40:45.808 INFO  [DocumentTemplate] content: null
  2456. 08.08 00:40:45.811 INFO  [DocumentTemplate] =====header=====
  2457. 08.08 00:40:45.811 INFO  [DocumentTemplate]                    jr. name                   ||NORMAL
  2458. 08.08 00:40:45.811 INFO  [DocumentTemplate]          199100, Spb, Savushkina, 112         ||NORMAL
  2459. 08.08 00:40:45.811 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  2460. 08.08 00:40:45.811 INFO  [DocumentTemplate] ЗВД.N:00000717161         ФН:      72afb605-7a||NORMAL
  2461. 08.08 00:40:45.811 INFO  [DocumentTemplate] РЕГ.N:NFM.7171.61.0.156519ИНН:     7802781104 ||NORMAL
  2462. 08.08 00:40:45.811 INFO  [DocumentTemplate] 01    Администраторов Адми     КАССА: 61 ОТД01||NORMAL
  2463. 08.08 00:40:45.812 INFO  [DocumentTemplate]   ЧЕК НА ПРОДАЖУ N:          183            ||NORMAL
  2464. 08.08 00:40:45.812 INFO  [DocumentTemplate]                                 СМЕНА N:      ||NORMAL
  2465. 08.08 00:40:45.812 INFO  [DocumentTemplate] =====text=====
  2466. 08.08 00:40:45.812 INFO  [DocumentTemplate] ----------------------------------------------||NORMAL
  2467. 08.08 00:40:45.812 INFO  [DocumentTemplate] Кассовый чек (ПРИХОД)                         ||NORMAL
  2468. 08.08 00:40:45.812 INFO  [DocumentTemplate]                *ПРОДАЖА ТОВАРА*               ||NORMAL
  2469. 08.08 00:40:45.819 INFO  [DocumentTemplate] =====positionSectionWithGoodSets=====
  2470. 08.08 00:40:45.819 INFO  [DocumentTemplate] ------------------------------------------||NORMAL
  2471. 08.08 00:40:45.819 INFO  [DocumentTemplate] Шоколад малиновый п   262.27     *1    =262.27||SMALL
  2472. 08.08 00:40:45.819 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2473. 08.08 00:40:45.819 INFO  [DocumentTemplate] Шоколад яблочный те     2.92     *1      =2.92||SMALL
  2474. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2475. 08.08 00:40:45.820 INFO  [DocumentTemplate] Напиток вишневый гу  1131.45     *1   =1131.45||SMALL
  2476. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2477. 08.08 00:40:45.820 INFO  [DocumentTemplate] Напиток клубничный   1254.69     *1   =1254.69||SMALL
  2478. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2479. 08.08 00:40:45.820 INFO  [DocumentTemplate] Кефир виноградный с   276.83     *1    =276.83||SMALL
  2480. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2481. 08.08 00:40:45.820 INFO  [DocumentTemplate] Йогурт яблочный кис   158.66     *1    =158.66||SMALL
  2482. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2483. 08.08 00:40:45.820 INFO  [DocumentTemplate] Хлеб клубничный сла  1098.43     *1   =1098.43||SMALL
  2484. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2485. 08.08 00:40:45.820 INFO  [DocumentTemplate] Кефир клубничный со   929.69     *1    =929.69||SMALL
  2486. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
  2487. 08.08 00:40:45.820 INFO  [DocumentTemplate] Шоколад яблочный те   782.92     *1    =782.92||SMALL
  2488. 08.08 00:40:45.820 INFO  [DocumentTemplate]     в т.ч. НДС 20%   ||SMALL
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!