API tools faq
paste
Advertisement
fedorm

Untitled

fedorm
Oct 28th, 2019
651
0
Never
Add comment
Not a member of Pastebin yet? Sign Up, it unlocks many cool features!
XML 63.62 KB | None | 0 0
raw download clone embed print report
  1. 28.10 13:52:57.466 TRACE [HibernateBackedCashAdvertisingActionDao] building hibernate session factory
  2. 28.10 13:53:00.587 TRACE [JdbcBackedCashAdvertisingActionDao] leaving postConstruct()
  3. 28.10 13:53:11.027 TRACE [AdvActionsCacheImpl] starting AdvActionsCacheImpl initialization in a separate thread
  4. 28.10 13:53:11.082 TRACE [AdvActionsCacheImpl] reading all active actions..
  5. 28.10 13:53:11.083 TRACE [AdvActionsCacheImpl] initActionsCache: lock on cache was obtained in 0 [ms]
  6. 28.10 13:53:11.101 TRACE [AdvActionsCacheImpl] clearing cache..
  7. 28.10 13:53:11.101 TRACE [AdvActionsCacheImpl] cache cleared
  8. 28.10 13:53:11.102 TRACE [AdvActionsCacheImpl] entering initActionsCacheComplete()
  9. 28.10 13:53:11.103 TRACE [JdbcBackedCashAdvertisingActionDao] entering getActionsByGuids(Collection, Date). The arguments are: guids [null], date: 2019-10-28T13:53:11.102+0300
  10. 28.10 13:53:11.404 TRACE [ActionIntrospectorImpl] <ActionIntrospector> was registered!
  11. 28.10 13:53:11.441 TRACE [ActionIntrospectorImpl] getActionTriggeringCouponsFromDB: query to execute: "SELECT a."value", c.periodstart, c.periodfinish, c.guid FROM discounts_action_plugin_property AS a INNER JOIN discounts_action_plugin AS b ON a.plugin_id = b.id INNER JOIN discounts_advertisingactions AS c ON b.action_id = c.id WHERE a."name" = 'couponNumber' AND length(a."value") > 0      AND b.class_name = 'ru.crystalservice.setv6.discounts.plugins.CouponsCondition'"
  12. 28.10 13:53:12.476 TRACE [ActionIntrospectorImpl] leaving getActionTriggeringCouponsFromDB(). the result is: {46126832=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@5bb51efa], 25072017=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@716b8bd8], 22023029=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@d071], 46126842=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@60141dcf], 22023028=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@5c3cac38], 46126853=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@453d5fae], 19911234=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@654a3a57], 111020172=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@166c7da8], 111020171=[ru.crystals.pos.loyal.cash.service.ActionIntrospectorImpl$ActionRange@7877e1fe]}; it took 1035 [ms]
  13. 28.10 13:53:14.088 TRACE [JdbcBackedCashAdvertisingActionDao] actions (withou collections) were extracted in 2855 [ms]
  14. 28.10 13:53:14.184 TRACE [JdbcBackedCashAdvertisingActionDao] entering pullCollections(Collection). The argument is: actions [size: 139]
  15. 28.10 13:53:16.128 TRACE [JdbcBackedCashAdvertisingActionDao] plugins were extracted and mapped in 1054 [ms]
  16. 28.10 13:53:17.093 TRACE [JdbcBackedCashAdvertisingActionDao] plugins properties were extracted and mapped in 963 [ms]
  17. 28.10 13:53:20.302 TRACE [HibernateBackedCashAdvertisingActionDao] hibernate session factory was built in 22832 [ms]
  18. 28.10 13:53:20.863 TRACE [JdbcBackedCashAdvertisingActionDao] master actions were extracted and mapped in 3769 [ms]
  19. 28.10 13:53:21.910 TRACE [JdbcBackedCashAdvertisingActionDao] result types were mapped in and mapped 1046 [ms]
  20. 28.10 13:53:21.996 TRACE [EventActionsServiceImpl] entering init()
  21. 28.10 13:53:22.017 INFO  [EventActionsServiceImpl] updating settings!
  22. 28.10 13:53:22.062 TRACE [EventActionsServiceImpl] entering readLocalSettingsIntoObject()
  23. 28.10 13:53:22.126 TRACE [JdbcBackedCashAdvertisingActionDao] no labels were extracted
  24. 28.10 13:53:22.126 TRACE [JdbcBackedCashAdvertisingActionDao] leaving pullCollections(Collection). It took 7944 [ms]
  25. 28.10 13:53:22.166 TRACE [JdbcBackedCashAdvertisingActionDao] leaving getActionsByGuids(Collection, Date). The result size is: 139; it took 11063 [ms]
  26. 28.10 13:53:25.456 TRACE [EventActionsServiceImpl] leaving readLocalSettingsIntoObject(). the result is: ru.crystals.pos.loyalty.EventActionsConnectionSettings@1f3c17e
  27. 28.10 13:53:25.718 TRACE [EventActionsServiceImpl] settings were reloaded. The result is: ru.crystals.pos.loyalty.EventActionsConnectionSettings@1f3c17e
  28. 28.10 13:53:25.721 TRACE [EventActionsServiceImpl] leaving init()
  29. 28.10 13:53:26.968 INFO  [CommonLogger] (NixNativeUtils) ADD NTP server
  30. 28.10 13:53:26.977 INFO  [CommonLogger] Executing command "sudo mv ntp.sh /opt/ntp.sh"...
  31. 28.10 13:53:27.401 INFO  [CommonLogger] Waiting "sudo mv ntp.sh /opt/ntp.sh" command to execute...
  32. 28.10 13:53:27.547 INFO  [CommonLogger] Process exited with code 0
  33. 28.10 13:53:27.574 INFO  [CommonLogger] Command response:
  34. 28.10 13:53:27.574 INFO  [CommonLogger] Executing command "sudo /opt/ntp.sh"...
  35. 28.10 13:53:27.606 INFO  [CommonLogger] Waiting "sudo /opt/ntp.sh" command to execute...
  36. 28.10 13:53:27.636 INFO  [CommonLogger] Process exited with code 1
  37. 28.10 13:53:27.636 INFO  [CommonLogger] Command response:
  38. 28.10 13:53:27.644 INFO  [CommonLogger] Executing command "sudo chmod u+x /opt/ntp.sh"...
  39. 28.10 13:53:27.665 INFO  [CommonLogger] Waiting "sudo chmod u+x /opt/ntp.sh" command to execute...
  40. 28.10 13:53:27.666 INFO  [CommonLogger] Process exited with code 0
  41. 28.10 13:53:27.666 INFO  [CommonLogger] Command response:
  42. 28.10 13:53:27.666 INFO  [CommonLogger] Executing command "cash save"...
  43. 28.10 13:53:27.748 INFO  [CommonLogger] Waiting "cash save" command to execute...
  44. 28.10 13:53:27.686 ERROR [PluginPropertiesSerializer] Restoration of the object-property [name: plugin, class: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult, value: null] failed!
  45. java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  46.     at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
  47.     at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
  48.     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
  49.     at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
  50.     at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
  51.     at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
  52.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
  53.     at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
  54.     at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
  55.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
  56.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
  57.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
  58.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
  59.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
  60.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
  61.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
  62.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
  63.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  64. 28.10 13:53:27.750 ERROR [ActionPluginSerializer] failed to deserialize plugin
  65. java.lang.IllegalArgumentException: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  66.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:300) ~[DataStructsModule.jar:10.2.75.0]
  67.     at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
  68.     at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
  69.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
  70.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
  71.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
  72.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
  73.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
  74.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
  75.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
  76.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
  77.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  78. Caused by: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  79.     at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
  80.     at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
  81.     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
  82.     at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
  83.     at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
  84.     at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
  85.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
  86.     ... 11 more
  87. 28.10 13:53:27.757 ERROR [AdvActionsCacheImpl] INVALID action [AdvertisingActionEntity{id=9691, guid=83472, parentGuid=null, name='СЧЕТЧИК ПО СУММЕ ЧЕКА', mode=UNCONDITIONAL, worksAnytime=true, useRestrictions=true, priority=1070.0, masterActionGuids=[]}, guid: 83472] was detected: not all plugins recognzed?
  88. 28.10 13:53:28.502 INFO  [CommonLogger] Process exited with code 0
  89. 28.10 13:53:30.534 INFO  [CommonLogger] Command response:
  90. 28.10 13:53:32.301 ERROR [PluginPropertiesSerializer] Restoration of the object-property [name: plugin, class: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult, value: null] failed!
  91. java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  92.     at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
  93.     at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
  94.     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
  95.     at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
  96.     at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
  97.     at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
  98.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
  99.     at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
  100.     at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
  101.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
  102.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
  103.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
  104.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
  105.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
  106.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
  107.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
  108.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
  109.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  110. 28.10 13:53:32.311 ERROR [ActionPluginSerializer] failed to deserialize plugin
  111. java.lang.IllegalArgumentException: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  112.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:300) ~[DataStructsModule.jar:10.2.75.0]
  113.     at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
  114.     at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
  115.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
  116.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
  117.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
  118.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
  119.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
  120.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
  121.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
  122.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
  123.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  124. Caused by: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  125.     at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
  126.     at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
  127.     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
  128.     at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
  129.     at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
  130.     at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
  131.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
  132.     ... 11 more
  133. 28.10 13:53:32.316 ERROR [AdvActionsCacheImpl] INVALID action [AdvertisingActionEntity{id=9714, guid=82823, parentGuid=81227, name='Счетчик по количеству чеков Обнуляется раз в 13 недель', mode=AUTOMATIC, worksAnytime=false, useRestrictions=false, priority=10.0, masterActionGuids=[]}, guid: 82823] was detected: not all plugins recognzed?
  134. 28.10 13:53:32.661 ERROR [PluginPropertiesSerializer] Restoration of the object-property [name: plugin, class: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult, value: null] failed!
  135. java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  136.     at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
  137.     at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
  138.     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
  139.     at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
  140.     at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
  141.     at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
  142.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
  143.     at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
  144.     at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
  145.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
  146.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
  147.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
  148.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
  149.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
  150.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
  151.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
  152.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
  153.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  154. 28.10 13:53:32.664 ERROR [ActionPluginSerializer] failed to deserialize plugin
  155. java.lang.IllegalArgumentException: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  156.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:300) ~[DataStructsModule.jar:10.2.75.0]
  157.     at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
  158.     at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
  159.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
  160.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
  161.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
  162.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
  163.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
  164.     at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
  165.     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
  166.     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
  167.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  168. Caused by: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
  169.     at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
  170.     at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
  171.     at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
  172.     at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
  173.     at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
  174.     at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
  175.     at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
  176.     ... 11 more
  177. 28.10 13:53:32.666 ERROR [AdvActionsCacheImpl] INVALID action [AdvertisingActionEntity{id=9697, guid=83099, parentGuid=79046, name='Счетчик по количеству товаров. Обнуляется раз в 13 недель', mode=AUTOMATIC, worksAnytime=false, useRestrictions=false, priority=10.0, masterActionGuids=[]}, guid: 83099] was detected: not all plugins recognzed?
  178. 28.10 13:53:33.423 TRACE [AdvActionsCacheImpl] leaving initActionsCacheComplete(). it took 22321 [ms]
  179. 28.10 13:53:33.423 INFO  [AdvActionsCacheImpl] Time of init actions cache: 22340 ms
  180. 28.10 13:53:56.842 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
  181. 28.10 13:53:57.392 INFO  [TransferManager] Nothing yet not processed on server to resend
  182. 28.10 13:53:58.556 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
  183. 28.10 13:53:58.665 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 1834 [ms]
  184. 28.10 13:54:34.166 TRACE [SMServiceImpl] entering init()
  185. 28.10 13:54:35.513 DEBUG [FileReader] Start FileTransportReader OPERDAY_TO_CASH
  186. 28.10 13:54:35.522 TRACE [FileReader] creating instance of FileTransferManager
  187. 28.10 13:54:35.525 TRACE [FileReader] create & schedule timer
  188. 28.10 13:54:35.528 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  189. 28.10 13:54:35.536 TRACE [MLServiceImpl] entering init()
  190. 28.10 13:54:35.538 INFO  [MLServiceImpl] updating settings!
  191. 28.10 13:54:35.557 TRACE [MLServiceImpl] entering readLocalSettingsIntoObject()
  192. 28.10 13:54:35.621 TRACE [MLServiceImpl] leaving readLocalSettingsIntoObject(). the result is: ml-con-settings [partner-id: 10; unit-id: null; pos: null; read-timeout: 5000; login: pl1\Victoria_Set10; password: nXFLuQ503; services: []; prefixes: []; holder-mandatory: false; enabled cashes: null; fake-card-no: "null"; action-guid: 0; i-method: ADD]
  193. 28.10 13:54:35.651 TRACE [MLServiceImpl] settings were reloaded. The result is: ml-con-settings [partner-id: Victoria; unit-id: 3388; pos: 1; read-timeout: 5000; login: testLogin; password: testPassword; services: [http://127.0.0.1:60324/sap/manzana?wsdl]; prefixes: [26, <:]; holder-mandatory: false; enabled cashes: null; fake-card-no: "2612341234"; action-guid: 0; i-method: ADD]; processing is enabled
  194. 28.10 13:54:35.704 TRACE [MLServiceImpl] leaving init()
  195. 28.10 13:54:35.805 TRACE [SCService] entering init()
  196. 28.10 13:54:35.807 INFO  [SCService] updating settings!
  197. 28.10 13:54:35.808 TRACE [SCService] entering readLocalSettingsIntoObject()
  198. 28.10 13:54:35.823 TRACE [SCService] leaving readLocalSettingsIntoObject(). the result is: sc-con-settings [pos-no: null; read-timeout: 5000; login: pl1\Victoria_Set10; password: nXFLuQ503; services: []; coupon-prefixes: []; enabled cashes: null]
  199. 28.10 13:54:35.845 TRACE [SCService] settings were reloaded. The result is: sc-con-settings [pos-no: 1; read-timeout: 2000; login: test-login; password: test-password; services: [http://127.0.0.1:8888/smch/emulator?wsdl, http://127.0.0.1:8888/smch/emulator?wsdl]; coupon-prefixes: [CL, 000000000000020939844]; enabled cashes: null]; processing is enabled
  200. 28.10 13:54:35.847 INFO  [SCService] looking up LoyFeedbackDao...
  201. 28.10 13:54:35.847 TRACE [SCService] leaving init()
  202. 28.10 13:54:36.638 INFO  [FiscalPrinterProxy] Try start provider for inn: null
  203. 28.10 13:54:36.690 INFO  [FiscalPrinter] Manual Exception has been restored. Exception has been canceled
  204. 28.10 13:54:36.889 DEBUG [AbstractFiscalPrinterEmulator] eth0
  205. 28.10 13:54:36.889 DEBUG [AbstractFiscalPrinterEmulator] InetAddress: 172.29.17.13
  206. 28.10 13:54:36.891 DEBUG [AbstractFiscalPrinterEmulator] java.rmi.server.hostname: 172.29.17.13
  207. 28.10 13:54:37.368 INFO  [AbstractFiscalPrinterEmulator] RMI Listening port: 8890
  208. 28.10 13:54:37.407 INFO  [FiscalPrinter] ---- FISCAL MODULE START ---- INN null -> true
  209. 28.10 13:54:37.651 INFO  [FiscalPrinter] Fiscal printer date: 2019-10-28T13:54:37.651+0300        current date: 2019-10-28T13:54:37.651+0300
  210. 28.10 13:54:37.653 INFO  [FiscalPrinter] Set requisites for inn: 7802781104
  211. 28.10 13:54:37.694 INFO  [FiscalPrinter] Set requisites - shop name: jr. name
  212. 28.10 13:54:37.695 INFO  [FiscalPrinter] Set requisites - shop address: 199100, Spb, Savushkina, 112
  213. 28.10 13:54:40.325 INFO  [FiscalPrinter] getRegNum
  214. 28.10 13:54:40.326 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
  215. 28.10 13:54:47.867 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  216. 28.10 13:54:47.989 TRACE [FileReader] getting new file..
  217. 28.10 13:54:48.026 TRACE [FileReader] No new file
  218. 28.10 13:54:48.026 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  219. 28.10 13:54:54.807 TRACE [SoftCheckService] entering init()
  220. 28.10 13:54:54.812 INFO  [SoftCheckService] updating settings!
  221. 28.10 13:54:54.821 TRACE [SoftCheckService] entering readLocalSettingsIntoObject()
  222. 28.10 13:54:54.842 TRACE [SoftCheckService] leaving readLocalSettingsIntoObject(). the result is: SoftCheckSettings [serviceAddress='localhost', barcodePrefix='707', cutPrefixCount=0, cutPrefix=false, numberLength=9, connectionTimeout=30000, port=8070, exciseAlcoholAllowed=false, fullServicePath='http://localhost:8070', requestAttemptCount='0', batchSize='10', delayStart='30000', period='30000', requestByShop='false', phoneCodes='[7, 8]', phoneLength='10', addPurchaseInfo=false]
  223. 28.10 13:54:55.076 TRACE [SoftCheckService] settings were reloaded. The result is: SoftCheckSettings [serviceAddress='localhost:8070', barcodePrefix='DP', cutPrefixCount=0, cutPrefix=false, numberLength=9, connectionTimeout=30000, port=8070, exciseAlcoholAllowed=false, fullServicePath='http://localhost:8070', requestAttemptCount='0', batchSize='10', delayStart='30000', period='30000', requestByShop='false', phoneCodes='[7, 8]', phoneLength='10', addPurchaseInfo=false]
  224. 28.10 13:54:55.077 TRACE [SoftCheckService] leaving init()
  225. 28.10 13:54:56.518 DEBUG [SoftCheckService] Service started. Settings SoftCheckSettings [serviceAddress='localhost:8070', barcodePrefix='DP', cutPrefixCount=0, cutPrefix=false, numberLength=9, connectionTimeout=30000, port=8070, exciseAlcoholAllowed=false, fullServicePath='http://localhost:8070', requestAttemptCount='0', batchSize='10', delayStart='30000', period='30000', requestByShop='false', phoneCodes='[7, 8]', phoneLength='10', addPurchaseInfo=false]
  226. 28.10 13:54:58.042 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  227. 28.10 13:54:58.174 TRACE [FileReader] getting new file..
  228. 28.10 13:54:58.256 TRACE [FileReader] No new file
  229. 28.10 13:54:58.256 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  230. 28.10 13:54:58.295 INFO  [SetApiShiftEventListener] class ru.crystals.pos.techprocess.SetApiShiftEventListener init method called
  231. 28.10 13:54:58.730 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
  232. 28.10 13:55:04.036 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
  233. 28.10 13:55:04.398 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 5669 [ms]
  234. 28.10 13:55:08.344 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  235. 28.10 13:55:08.356 TRACE [FileReader] getting new file..
  236. 28.10 13:55:08.416 TRACE [FileReader] No new file
  237. 28.10 13:55:08.416 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  238. 28.10 13:55:11.069 ERROR [CashMachinePaymentController] Fail to get cash machine inventory. Cash machine is not initialized.
  239. 28.10 13:55:11.156 INFO  [CashMachinePaymentController] denomination auto detected value is 1
  240. 28.10 13:55:14.983 INFO  [PaymentsServiceImpl] Add external payment plugin: foo.service.payment
  241. 28.10 13:55:17.418 INFO  [CommonLogger] ---{ START OF MODULE }---
  242. 28.10 13:55:17.860 INFO  [KeyboardConfigLoader] Keyboard loaded - qwerty , config/plugins/keyboard-qwerty-0-kbd.xml
  243. 28.10 13:55:18.226 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  244. 28.10 13:55:18.226 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  245. 28.10 13:55:18.226 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  246. 28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  247. 28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  248. 28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  249. 28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  250. 28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  251. 28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  252. 28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  253. 28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  254. 28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  255. 28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  256. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  257. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  258. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  259. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  260. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  261. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  262. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  263. 28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  264. 28.10 13:55:18.230 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  265. 28.10 13:55:18.230 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
  266. 28.10 13:55:18.604 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  267. 28.10 13:55:18.670 TRACE [FileReader] getting new file..
  268. 28.10 13:55:18.738 TRACE [FileReader] No new file
  269. 28.10 13:55:18.865 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  270. 28.10 13:55:19.221 INFO  [FiscalPrinter] getFactoryNum
  271. 28.10 13:55:19.226 INFO  [FiscalPrinter] FactoryNum = 0000033881
  272. 28.10 13:55:19.227 INFO  [FiscalPrinter] getRegNum
  273. 28.10 13:55:19.228 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
  274. 28.10 13:55:19.228 INFO  [FiscalPrinter] getEklzNum
  275. 28.10 13:55:19.229 INFO  [FiscalPrinter] EklzNum = 6de03059-181e-4147-b738-705af76216f2
  276. 28.10 13:55:19.255 DEBUG [TechProcessImpl] Server online mode
  277. 28.10 13:55:19.309 INFO  [FiscalPrinter] getVerBios
  278. 28.10 13:55:19.310 INFO  [FiscalPrinter] VerBios = 27
  279. 28.10 13:55:19.179 ERROR [ExternalEncryptedEventPacket] Thread-46   Ошибка расшифровки пакета
  280. java.security.InvalidKeyException: Unwrapping failed
  281.     at com.sun.crypto.provider.RSACipher.engineUnwrap(RSACipher.java:445) ~[sunjce_provider.jar:1.8.0_112]
  282.     at javax.crypto.Cipher.unwrap(Cipher.java:2550) ~[?:1.8.0_121]
  283.     at ru.crystals.pos.prismabridge.external.ExternalPacketCipher.encryptAesKey(ExternalPacketCipher.java:57) ~[prismaBridge.jar:10.2.75.0]
  284.     at ru.crystals.pos.prismabridge.external.ExternalPacketCipher.decode(ExternalPacketCipher.java:48) ~[prismaBridge.jar:10.2.75.0]
  285.     at ru.crystals.pos.prismabridge.external.ExternalEncryptedEventPacket.parseEvent(ExternalEncryptedEventPacket.java:44) [prismaBridge.jar:10.2.75.0]
  286.     at ru.crystals.pos.emulator.prisma.PrismaEmulatorRunnable.decodePacket(PrismaEmulatorRunnable.java:168) [PrismaEmulator.jar:?]
  287.     at ru.crystals.pos.emulator.prisma.PrismaEmulatorRunnable.readBytes(PrismaEmulatorRunnable.java:91) [PrismaEmulator.jar:?]
  288.     at ru.crystals.pos.emulator.prisma.PrismaEmulatorRunnable.run(PrismaEmulatorRunnable.java:71) [PrismaEmulator.jar:?]
  289.     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
  290. Caused by: javax.crypto.BadPaddingException: Decryption error
  291.     at sun.security.rsa.RSAPadding.unpadV15(RSAPadding.java:380) ~[?:1.8.0_112]
  292.     at sun.security.rsa.RSAPadding.unpad(RSAPadding.java:291) ~[?:1.8.0_112]
  293.     at com.sun.crypto.provider.RSACipher.doFinal(RSACipher.java:363) ~[sunjce_provider.jar:1.8.0_112]
  294.     at com.sun.crypto.provider.RSACipher.engineUnwrap(RSACipher.java:440) ~[sunjce_provider.jar:1.8.0_112]
  295.     ... 8 more
  296. 28.10 13:55:19.417 INFO  [CheckServiceLoaderImpl] ---- PRIMARY CHECK MODULE FiscalVO{factoryNum=0000033881, fiscalNum=NFM.3388.1.0.1571827454607, eklzNum=6de03059-181e-4147-b738-705af76216f2, innNum=7802781104, hardwareName=Fiscal printer emulator 0, fiscalDate=28.09.2019, fwVersion=27} ----
  297. 28.10 13:55:19.422 INFO  [FiscalPrinter] getRegNum
  298. 28.10 13:55:19.423 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
  299. 28.10 13:55:19.423 INFO  [FiscalPrinter] getShiftNumber
  300. 28.10 13:55:19.425 INFO  [FiscalPrinter] ShiftNumber = 5
  301. 28.10 13:55:19.426 INFO  [FiscalPrinter] isShiftOpen
  302. 28.10 13:55:19.427 INFO  [FiscalPrinter] getLastKpk
  303. 28.10 13:55:19.428 INFO  [FiscalPrinter] LastKpk = 7
  304. 28.10 13:55:19.429 INFO  [FiscalPrinter] getCountCashIn
  305. 28.10 13:55:19.429 INFO  [FiscalPrinter] CountCashIn = 0
  306. 28.10 13:55:19.429 INFO  [FiscalPrinter] getCountCashOut
  307. 28.10 13:55:19.429 INFO  [FiscalPrinter] CountCashOut = 0
  308. 28.10 13:55:19.429 INFO  [FiscalPrinter] getCountAnnul
  309. 28.10 13:55:19.429 INFO  [FiscalPrinter] CountAnnul = 0
  310. 28.10 13:55:19.430 INFO  [FiscalPrinter] getSPND
  311. 28.10 13:55:19.430 INFO  [FiscalPrinter] CountSPND = 11
  312. 28.10 13:55:19.430 INFO  [FiscalPrinter] getCashAmount
  313. 28.10 13:55:19.430 INFO  [FiscalPrinter] CashAmount = 14166
  314. 28.10 13:55:19.492 INFO  [FiscalPrinter] ru.crystals.pos.check.ShiftStatusData@df4a72[regNum=NFM.3388.1.0.1571827454607,shiftNum=5,isShiftOpen=true,lastKpk=7,countCashIn=0,countCashOut=0,countAnnul=0,spnd=11,countPurchases=<null>,docToRecover=<null>,lastCloseDocument=FiscalDocumentData{type=SALE, numPurchase=7, numDocument=11, summ=10757, numFD=7},shiftClosurePending=true,cashAmount=14166,id=<null>]
  315. 28.10 13:55:19.565 TRACE [TechProcessShift] entering getLastShift()
  316. 28.10 13:55:22.133 TRACE [TechProcessShift] leaving getLastShift(). the result [found locally] is: ShiftEntity [cashNum=1, eklzNum=6de03059-181e-4147-b738-705af76216f2, fiscalNum=NFM.3388.1.0.1571827454607, fiscalSum=null, numShift=5, shiftClose=null, shiftOpen=null, toString()=ru.crystals.pos.check.ShiftEntity@280]; it took 2567 [ms]
  317. 28.10 13:55:22.139 INFO  [TechProcessShift] fiscalRegNum = FiscalVO{factoryNum=0000033881, fiscalNum=NFM.3388.1.0.1571827454607, eklzNum=6de03059-181e-4147-b738-705af76216f2, innNum=7802781104, hardwareName=Fiscal printer emulator 0, fiscalDate=28.09.2019, fwVersion=27}
  318. 28.10 13:55:23.539 INFO  [TechProcessShift] Смены совпадают, ожидается синхронизация по документам и счетчикам.
  319. 28.10 13:55:23.541 INFO  [TechProcessShift] Счетчики смен совпадают.
  320. 28.10 13:55:23.549 INFO  [TechProcessShift] Синхронизация пройдена.
  321. 28.10 13:55:23.683 WARN  [SessionNormalizer] Last session id=720 has not been end properly (no end date)
  322. 28.10 13:55:23.822 INFO  [SessionNormalizer] Last session end time will be set from lastWorkTime (2019-10-28T13:51:10)
  323. 28.10 13:55:23.959 INFO  [TransferManager] OperDayMessanger - UserLogOut
  324. 28.10 13:55:24.211 WARN  [TechProcessShift] Некорректный документ для восстановления:PurchaseEntity [id=680, number=null, dateCreate=2019-10-28 12:45:38.812, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  325. 28.10 13:55:24.485 TRACE [CheckService] entering restoreNonFiscalChecks()
  326. 28.10 13:55:24.490 WARN  [CheckService] restoring non-fiscalized receipt [id: 680]
  327. 28.10 13:55:24.490 TRACE [CheckService] entering setCheckToWork(Long, boolean). the arguments are: idPurchase [680], notifyListeners [true]
  328. 28.10 13:55:24.621 DEBUG [ChecksHandler] Setting check: PurchaseEntity [id=680, number=null, dateCreate=2019-10-28 12:45:38.812, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]
  329. 28.10 13:55:24.623 TRACE [TechProcessImpl] entering updateCheck(PurchaseEntity, int). The arguments are: check [PurchaseEntity [id=680, number=null, dateCreate=2019-10-28 12:45:38.812, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]], checkNum [0]
  330. 28.10 13:55:24.665 TRACE [TechProcessImpl] leaving updateCheck(PurchaseEntity, int)
  331. 28.10 13:55:24.666 TRACE [CheckService] leaving setCheckToWork(Long, boolean)
  332. 28.10 13:55:24.666 TRACE [CheckService] leaving restoreNonFiscalChecks()
  333. 28.10 13:55:25.586 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00818]
  334. 28.10 13:55:25.649 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00515]
  335. 28.10 13:55:25.653 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00616]
  336. 28.10 13:55:25.655 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00888]
  337. 28.10 13:55:25.658 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00919]
  338. 28.10 13:55:26.551 TRACE [HibernateBackedLoyTxDao] entering getLoyTxByReceipt(PurchaseEntity). The argument is: purchase  [PurchaseEntity [id=680, number=null, dateCreate=2019-10-28 12:45:38.812, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]]
  339. 28.10 13:55:26.556 TRACE [HibernateBackedLoyTxDao] loy-tx-id of the receipt [PurchaseEntity [id=680, number=null, dateCreate=2019-10-28 12:45:38.812, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]] IS NULL
  340. 28.10 13:55:26.557 WARN  [HibernateBackedLoyTxDao] leaving getLoyTxByReceipt(PurchaseEntity): at least one of the mandaroty fields (either doc-num: null, or operation-type: true, or shop-num: null, or shift-num: null, or cash-num: null) of the receipt [PurchaseEntity [id=680, number=null, dateCreate=2019-10-28 12:45:38.812, dateCommit=null, fiscalDocNum=null, sentToServerStatus=NO_SENT]] is NULL! So, NULL will be returned!
  341. 28.10 13:55:26.557 TRACE [TechProcessShift] entering TP.findNotCommitedChecks()
  342. 28.10 13:55:26.559 TRACE [TechProcessShift] TP.findNotCommitedChecks(): current shift is: ShiftEntity [cashNum=1, eklzNum=6de03059-181e-4147-b738-705af76216f2, fiscalNum=NFM.3388.1.0.1571827454607, fiscalSum=null, numShift=5, shiftClose=null, shiftOpen=null, toString()=ru.crystals.pos.check.ShiftEntity@280]
  343. 28.10 13:55:26.579 TRACE [TechProcessShift] leaving TP.findNotCommitedChecks()
  344. 28.10 13:55:26.635 TRACE [KeyboardImpl] creating KLocker. timeout = 20 [ms], contact-bounce-time = 100 [ms]
  345. 28.10 13:55:30.058 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  346. 28.10 13:55:30.666 TRACE [FileReader] getting new file..
  347. 28.10 13:55:31.030 TRACE [FileReader] No new file
  348. 28.10 13:55:31.033 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  349. 28.10 13:55:34.405 INFO  [SetApiLoyaltyPluginBackgroundWorker] Cards pending operation sender started
  350. 28.10 13:55:34.411 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Polling...
  351. 28.10 13:55:34.411 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
  352. 28.10 13:55:34.768 INFO  [PendingOperationQueue] No pending card operations found.
  353. 28.10 13:55:34.981 INFO  [SetApiPluginLoyProvider] class ru.crystals.pos.loyal.SetApiPluginLoyProvider started
  354. 28.10 13:55:40.411 DEBUG [HibernateBackedActionsTransportAuxiliariesDao] building hibernate session factory
  355. 28.10 13:55:40.616 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  356. 28.10 13:55:41.038 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  357. 28.10 13:55:41.040 TRACE [FileReader] getting new file..
  358. 28.10 13:55:41.177 TRACE [FileReader] No new file
  359. 28.10 13:55:41.178 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  360. 28.10 13:55:41.262 TRACE [JdbcBackedLoyFeedbackDao] entering postConstruct()
  361. 28.10 13:55:41.264 INFO  [JdbcBackedLoyFeedbackDao] creating jdbcMapper...
  362. 28.10 13:55:42.287 TRACE [JdbcBackedLoyFeedbackDao] leaving postConstruct()
  363. 28.10 13:55:42.775 TRACE [AbstractCleaner] entering start()
  364. 28.10 13:55:42.786 INFO  [AbstractCleaner] <InternalCashPoolExecutor> was added. Starting the cleaner thread
  365. 28.10 13:55:42.883 INFO  [AbstractCleaner] cleaner thread was scheduled [initial-delay: 30; interval: 3600; to-remove-at-once: 1000]
  366. 28.10 13:55:42.884 TRACE [AbstractCleaner] leaving start()
  367. 28.10 13:55:43.144 TRACE [AbstractCleaner] entering start()
  368. 28.10 13:55:43.144 INFO  [AbstractCleaner] <InternalCashPoolExecutor> was added. Starting the cleaner thread
  369. 28.10 13:55:43.534 INFO  [AbstractCleaner] cleaner thread was scheduled [initial-delay: 30; interval: 3600; to-remove-at-once: 1000]
  370. 28.10 13:55:43.539 TRACE [AbstractCleaner] leaving start()
  371. 28.10 13:55:49.260 DEBUG [TechProcessImpl] Server online mode
  372. 28.10 13:55:50.678 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  373. 28.10 13:55:50.850 INFO  [CommonLogger] Executing command "sudo test-pcx"...
  374. 28.10 13:55:51.214 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  375. 28.10 13:55:51.367 TRACE [FileReader] getting new file..
  376. 28.10 13:55:51.381 INFO  [CommonLogger] Waiting "sudo test-pcx" command to execute...
  377. 28.10 13:55:51.481 TRACE [FileReader] No new file
  378. 28.10 13:55:51.483 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  379. 28.10 13:55:52.888 INFO  [CommonLogger] Process exited with code 0
  380. 28.10 13:55:52.937 INFO  [CommonLogger] Command response:
  381. 28.10 13:55:52.938 INFO  [CommonLogger] ----Разбор аргументов командной строки-----------
  382. 28.10 13:55:52.938 INFO  [CommonLogger] Демонстрационный тест выполнения операций через PCX
  383. 28.10 13:55:52.938 INFO  [CommonLogger] Будут выполнены :
  384. 28.10 13:55:52.938 INFO  [CommonLogger]   - эхо запрос к ПЦ
  385. 28.10 13:55:52.938 INFO  [CommonLogger]   - запрос состояния счета бонусной карты
  386. 28.10 13:55:52.938 INFO  [CommonLogger]   - оплата товара баллами
  387. 28.10 13:55:52.938 INFO  [CommonLogger]   - операция начисления баллов
  388. 28.10 13:55:52.938 INFO  [CommonLogger]   - отмена операции оплаты баллов
  389. 28.10 13:55:52.938 INFO  [CommonLogger]   - отмена операции начисления баллов
  390. 28.10 13:55:52.938 INFO  [CommonLogger] Usage : test_linpcx [-P PartnerID] [-L Location] [-T Terminal] [-C ConnectionString] [-PH ProxyHost] [-PP ProxyPort] [-PU ProxyUserId] [-PW ProxyUserPass] [-CA CertFilePath] [-KF KeyFilePath] [-KP KeyPassword] [-CID ClientID] [-CT ClientIDType]
  391. 28.10 13:55:52.938 INFO  [CommonLogger] ----Инициализация PCX----------------------------------------------
  392. 28.10 13:55:52.938 INFO  [CommonLogger] Executing command "test-pcx"...
  393. 28.10 13:55:53.188 INFO  [CommonLogger] Waiting "test-pcx" command to execute...
  394. 28.10 13:55:53.498 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 2823 [ms]
  395. 28.10 13:55:53.846 TRACE [ActionsFilesReader] no new files; last id = 85909
  396. 28.10 13:55:53.846 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  397. 28.10 13:55:54.276 INFO  [CommonLogger] Process exited with code 0
  398. 28.10 13:55:54.277 INFO  [CommonLogger] Command response:
  399. 28.10 13:55:54.277 INFO  [CommonLogger] ----Разбор аргументов командной строки-----------
  400. 28.10 13:55:54.277 INFO  [CommonLogger] Демонстрационный тест выполнения операций через PCX
  401. 28.10 13:55:54.277 INFO  [CommonLogger] Будут выполнены :
  402. 28.10 13:55:54.277 INFO  [CommonLogger]   - эхо запрос к ПЦ
  403. 28.10 13:55:54.277 INFO  [CommonLogger]   - запрос состояния счета бонусной карты
  404. 28.10 13:55:54.278 INFO  [CommonLogger]   - оплата товара баллами
  405. 28.10 13:55:54.278 INFO  [CommonLogger]   - операция начисления баллов
  406. 28.10 13:55:54.278 INFO  [CommonLogger]   - отмена операции оплаты баллов
  407. 28.10 13:55:54.278 INFO  [CommonLogger]   - отмена операции начисления баллов
  408. 28.10 13:55:54.278 INFO  [CommonLogger] Usage : test_linpcx [-P PartnerID] [-L Location] [-T Terminal] [-C ConnectionString] [-PH ProxyHost] [-PP ProxyPort] [-PU ProxyUserId] [-PW ProxyUserPass] [-CA CertFilePath] [-KF KeyFilePath] [-KP KeyPassword] [-CID ClientID] [-CT ClientIDType]
  409. 28.10 13:55:54.278 INFO  [CommonLogger] ----Инициализация PCX----------------------------------------------
  410. 28.10 13:55:54.278 INFO  [CommonLogger] Объект PCX создан !
  411. 28.10 13:55:55.192 ERROR [CFTBridgeImpl] Error loading CFT bridge module: Ошибка инициализации SSL:
  412. 28.10 13:55:58.014 INFO  [TransferManager] Nothing yet not processed on server to resend
  413. 28.10 13:55:59.704 INFO  [CommonLogger] Executing command "sudo test-pcx"...
  414. 28.10 13:55:59.839 INFO  [CommonLogger] Waiting "sudo test-pcx" command to execute...
  415. 28.10 13:56:01.073 INFO  [CommonLogger] Process exited with code 0
  416. 28.10 13:56:01.112 INFO  [CommonLogger] Command response:
  417. 28.10 13:56:01.112 INFO  [CommonLogger] ----Разбор аргументов командной строки-----------
  418. 28.10 13:56:01.112 INFO  [CommonLogger] Демонстрационный тест выполнения операций через PCX
  419. 28.10 13:56:01.129 INFO  [CommonLogger] Будут выполнены :
  420. 28.10 13:56:01.129 INFO  [CommonLogger]   - эхо запрос к ПЦ
  421. 28.10 13:56:01.129 INFO  [CommonLogger]   - запрос состояния счета бонусной карты
  422. 28.10 13:56:01.129 INFO  [CommonLogger]   - оплата товара баллами
  423. 28.10 13:56:01.129 INFO  [CommonLogger]   - операция начисления баллов
  424. 28.10 13:56:01.129 INFO  [CommonLogger]   - отмена операции оплаты баллов
  425. 28.10 13:56:01.129 INFO  [CommonLogger]   - отмена операции начисления баллов
  426. 28.10 13:56:01.129 INFO  [CommonLogger] Usage : test_linpcx [-P PartnerID] [-L Location] [-T Terminal] [-C ConnectionString] [-PH ProxyHost] [-PP ProxyPort] [-PU ProxyUserId] [-PW ProxyUserPass] [-CA CertFilePath] [-KF KeyFilePath] [-KP KeyPassword] [-CID ClientID] [-CT ClientIDType]
  427. 28.10 13:56:01.129 INFO  [CommonLogger] ----Инициализация PCX----------------------------------------------
  428. 28.10 13:56:01.132 INFO  [CommonLogger] Executing command "test-pcx"...
  429. 28.10 13:56:01.175 INFO  [CommonLogger] Waiting "test-pcx" command to execute...
  430. 28.10 13:56:01.604 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  431. 28.10 13:56:01.734 TRACE [FileReader] getting new file..
  432. 28.10 13:56:01.819 TRACE [FileReader] No new file
  433. 28.10 13:56:01.821 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  434. 28.10 13:56:02.662 INFO  [CommonLogger] Process exited with code 0
  435. 28.10 13:56:02.749 INFO  [CommonLogger] Command response:
  436. 28.10 13:56:03.444 ERROR [CFTBridgeImpl] Error loading CFT bridge module: Ошибка инициализации SSL:
  437. 28.10 13:56:03.850 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  438. 28.10 13:56:03.917 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 67 [ms]
  439. 28.10 13:56:04.025 TRACE [ActionsFilesReader] no new files; last id = 85909
  440. 28.10 13:56:04.027 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  441. 28.10 13:56:04.742 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
  442. 28.10 13:56:05.185 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
  443. 28.10 13:56:05.186 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 444 [ms]
  444. 28.10 13:56:11.833 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  445. 28.10 13:56:11.852 TRACE [FileReader] getting new file..
  446. 28.10 13:56:11.862 TRACE [FileReader] No new file
  447. 28.10 13:56:11.863 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  448. 28.10 13:56:12.902 TRACE [LoyTxCleanerWorkhorse] entering run()
  449. 28.10 13:56:12.906 INFO  [LoyTxCleanerWorkhorse] shopNo: 3388
  450. 28.10 13:56:12.906 INFO  [LoyTxCleanerWorkhorse] cashNo: 1
  451. 28.10 13:56:12.906 INFO  [LoyTxCleanerWorkhorse] shiftsToKeep: 0
  452. 28.10 13:56:12.907 INFO  [LoyTxCleanerWorkhorse] inn: 7802781104
  453. 28.10 13:56:12.908 TRACE [LoyTxCleanerWorkhorse] leaving run(): seems the feature (trim-off superfluous docs) is disabled. shifts-to-keep: 0
  454. 28.10 13:56:13.535 TRACE [ActionsCleanerWorkhorse] entering run()
  455. 28.10 13:56:13.536 INFO  [ActionsCleanerWorkhorse] looking up <LoyTxDao>
  456. 28.10 13:56:13.539 TRACE [JdbcBackedCashAdvertisingActionDao] entering removeStaleActions(int). The argument maxRecordsToRemoveAtOnce is: 1000
  457. 28.10 13:56:14.038 TRACE [JdbcBackedCashAdvertisingActionDao] leaving removeStaleActions(int). The result deleted is: 0; it took 500 [ms]
  458. 28.10 13:56:14.039 TRACE [ActionsCleanerWorkhorse] leaving run(), removed 0 stale actions
  459. 28.10 13:56:14.033 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  460. 28.10 13:56:14.111 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 81 [ms]
  461. 28.10 13:56:14.117 INFO  [AeroflotBonusesServiceImpl] --- Start service ---
  462. 28.10 13:56:14.131 INFO  [AeroflotBonusesServiceImpl] updating settings!
  463. 28.10 13:56:14.132 TRACE [AeroflotBonusesServiceImpl] entering readLocalSettingsIntoObject()
  464. 28.10 13:56:14.136 TRACE [ActionsFilesReader] no new files; last id = 85909
  465. 28.10 13:56:14.137 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  466. 28.10 13:56:14.400 TRACE [AeroflotBonusesServiceImpl] leaving readLocalSettingsIntoObject(). the result is: AeroflotBonusesSettings{url='', timeout=30000, partnerId=0, certificatePassword='', minAmountDiscountMiles=1, location='', terminal='', certificatePath='modules/aeroflotBonusesCFT/CFT.pfx'}
  467. 28.10 13:56:14.442 TRACE [AeroflotBonusesServiceImpl] settings were reloaded. The result is: AeroflotBonusesSettings{url='http://127.0.0.1:50052/CFTAeroflotBonuses', timeout=10000000, partnerId=0, certificatePassword='', minAmountDiscountMiles=1, location='', terminal='', certificatePath='modules/aeroflotBonusesCFT/CFT.pfx'}
  468. 28.10 13:56:14.466 INFO  [AeroflotBonusesWsClient] Rebuild ws client url = 'http://127.0.0.1:50052/CFTAeroflotBonuses', certificatePath ='modules/aeroflotBonusesCFT/CFT.pfx', certificatePassword = '', timeout = '10000000'
  469. 28.10 13:56:14.471 ERROR [AeroflotBonusesWsClient] Unable to load certificate: file "modules/aeroflotBonusesCFT/CFT.pfx" is not found
  470. 28.10 13:56:20.318 DEBUG [TechProcessImpl] Server online mode
  471. 28.10 13:56:21.969 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  472. 28.10 13:56:21.993 TRACE [FileReader] getting new file..
  473. 28.10 13:56:22.002 TRACE [FileReader] No new file
  474. 28.10 13:56:22.065 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  475. 28.10 13:56:23.417 INFO  [AeroflotBonusesWsClient] Client successfully rebuild by url = 'http://127.0.0.1:50052/CFTAeroflotBonuses', timeout = '10000000'
  476. 28.10 13:56:23.471 INFO  [AeroflotBonusesServiceImpl] Loaded parameters = AeroflotBonusesSettings{url='http://127.0.0.1:50052/CFTAeroflotBonuses', timeout=10000000, partnerId=0, certificatePassword='', minAmountDiscountMiles=1, location='', terminal='', certificatePath='modules/aeroflotBonusesCFT/CFT.pfx'}
  477. 28.10 13:56:23.647 INFO  [SiebelServiceImpl] SiebelService with configuration: ru.crystals.siebel.SiebelServiceConfig@a22666[cardStatusConnectTimeout=15000,cardStatusRequestTimeout=15000,calculateConnectTimeout=15000,calculateRequestTimeout=15000,redeemConnectTimeout=3000,redeemRequestTimeout=3000,pendingOperationBatchSize=50,pendingOperationsRepeatInterval=60,pendingOperationsMaxRetries=0,wsdlUrl=file:/mnt/sda1/tce/storage/crystal-cash/modules/siebelBridge/wsdl/siebel-azbuka-testserver.wsdl,wsdlFile=modules/siebelBridge/wsdl/siebel-azbuka-testserver.wsdl,cardNumberLength=4,shopIndex=902,cashType=POS,discountNameMap={1=Фиксированная цена, 2=Скидка на ШК, 3=Скидка на товар, 4=Скидка на группу товаров, 5=Скидка на кол-во по товару, 6=Скидка на кол-во по группе, 7=Ручная скидка, 8=Скидка на группу продаж, 9=Скидка на кол-во по гр. продаж, 10=Скидка на товар по кат. ДК, 11=Скидка на сумму чека, 12=Скидка по ДК, 13=Скидка на группу по ДК, 14=Скидка на сумму по ДК, 15=Скидка на чек, 16=Скидка на кол-во по груп.ДК, 17=Скидка на гр.прод.по ДК, 18=Скидка на кол.по груп.пр.ДК, 19=Скидка на груп.по кат.ДК, 20=Скидка на вид оплат, 21=Скидка на набор, 22=Скидка по купону, 23=Скидка на сум.чека по кат.ДК, 24=Соц карта, 25=Скидка на отдел, 26=Скидка на кол-во чеков, 27=Скидка на ДР, 28=Скидка на товар в отд, 29=Скидка на округление, 30=Скидка по бонусам, 31=Скидка на сум.Груп.Тов, 32=Скидка на кат.клиента.ДК, 33=Скидка на кол-во,Груп.Продаж, 34=Скидка на потов.кол.ГП, 35=________1., 36=________2., 37=________3., 38=________4., 39=________5., 110=Марки, 112=Промо-код, 5005=Подарок},giftCardPrefixesString=<null>,discTypeFromActionAnyway=false]
  478. 28.10 13:56:23.654 DEBUG [SiebelServiceImpl] create ws-client..
  479. 28.10 13:56:23.709 DEBUG [SiebelServiceImpl] register SiebelService in BundleManager..
  480. 28.10 13:56:23.731 DEBUG [SiebelServiceImpl] Registered
  481. 28.10 13:56:24.138 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  482. 28.10 13:56:24.565 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 420 [ms]
  483. 28.10 13:56:24.630 TRACE [ActionsFilesReader] no new files; last id = 85909
  484. 28.10 13:56:24.635 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  485. 28.10 13:56:24.863 INFO  [ConfiguratorCashClient] Current version: 10.2.75.0, topologyAddress: 1.0.3388.1, cashType: POS
  486. 28.10 13:56:24.888 INFO  [ConfiguratorCashClient] Initialized topologyPoint: ConfigurationTopologyPoint {
  487.   type=POS,
  488.   topologyAddress=1.0.3388.1,
  489.   status=IN_WORK,
  490.   currentVersion=10.2.75.0,
  491.   previousVersion=,
  492.   planningVersion=,
  493.   topologyPointIP=172.29.17.13,
  494.   updateTime=null,
  495.   needMakeDbBackup=true,
  496.   needAutomaticRestart=null,
  497.   shiftMustBeClosed=false,
  498.   waitUpdateCommand=false,
  499.   localPatches=null,
  500.   online=false}
  501. 28.10 13:56:24.891 INFO  [ConfiguratorCashClient] Updates path /mnt/sda1/tce/storage/crystal-conf/updates
  502. 28.10 13:56:27.794 INFO  [CashConfigurationUpdateChecker] Waiting cdl...
  503. 28.10 13:56:27.821 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  504. 28.10 13:56:28.009 INFO  [CommonLogger] POS loaded in 307 sec
  505. 28.10 13:56:32.116 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  506. 28.10 13:56:32.141 TRACE [FileReader] getting new file..
  507. 28.10 13:56:32.210 TRACE [FileReader] No new file
  508. 28.10 13:56:32.215 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  509. 28.10 13:56:34.636 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  510. 28.10 13:56:34.716 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 80 [ms]
  511. 28.10 13:56:34.834 TRACE [ActionsFilesReader] no new files; last id = 85909
  512. 28.10 13:56:34.837 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  513. 28.10 13:56:45.432 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  514. 28.10 13:56:45.432 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  515. 28.10 13:56:46.191 TRACE [FileReader] getting new file..
  516. 28.10 13:56:46.300 TRACE [FileReader] No new file
  517. 28.10 13:56:46.306 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  518. 28.10 13:56:46.406 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 1075 [ms]
  519. 28.10 13:56:46.440 TRACE [ActionsFilesReader] no new files; last id = 85909
  520. 28.10 13:56:46.442 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  521. 28.10 13:56:47.222 INFO  [CommonLogger] Time of starting visualization = 26 ms, totalMemory = 236781568, maxMemory = 259522560, freeMemory = 89668336
  522. 28.10 13:56:49.250 INFO  [DocumentSender] ping = true
  523. 28.10 13:56:49.480 INFO  [TransferManager] Message [userLogOut] has been sent
  524. 28.10 13:56:50.505 DEBUG [TechProcessImpl] Server online mode
  525. 28.10 13:56:52.245 INFO  [FiscalPrinter] getFactoryNum
  526. 28.10 13:56:52.249 INFO  [FiscalPrinter] FactoryNum = 0000033881
  527. 28.10 13:56:52.249 INFO  [FiscalPrinter] getRegNum
  528. 28.10 13:56:52.314 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
  529. 28.10 13:56:52.315 INFO  [FiscalPrinter] getEklzNum
  530. 28.10 13:56:52.315 INFO  [FiscalPrinter] EklzNum = 6de03059-181e-4147-b738-705af76216f2
  531. 28.10 13:56:52.316 INFO  [FiscalPrinter] getVerBios
  532. 28.10 13:56:52.316 INFO  [FiscalPrinter] VerBios = 27
  533. 28.10 13:56:53.748 TRACE [AeroflotBonusesServiceImpl] Not found pending operations
  534. 28.10 13:56:56.316 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  535. 28.10 13:56:56.376 TRACE [FileReader] getting new file..
  536. 28.10 13:56:56.433 TRACE [FileReader] No new file
  537. 28.10 13:56:56.433 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  538. 28.10 13:56:56.444 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  539. 28.10 13:56:57.240 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 796 [ms]
  540. 28.10 13:56:57.508 TRACE [ActionsFilesReader] no new files; last id = 85909
  541. 28.10 13:56:57.508 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  542. 28.10 13:56:57.505 TRACE [DocumentSender] entering getDocuments()
  543. 28.10 13:56:58.289 TRACE [DocumentSender] leaving getDocuments(). The result size is: 0; it took 791 [ms]
  544. 28.10 13:56:58.594 INFO  [TransferManager] OD found 0 documents to register
  545. 28.10 13:56:58.882 INFO  [DocumentSender] OD found 0 transactions to register
  546. 28.10 13:57:05.223 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
  547. 28.10 13:57:06.725 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  548. 28.10 13:57:06.730 TRACE [FileReader] getting new file..
  549. 28.10 13:57:06.823 TRACE [FileReader] No new file
  550. 28.10 13:57:06.827 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  551. 28.10 13:57:06.977 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
  552. 28.10 13:57:06.982 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 1760 [ms]
  553. 28.10 13:57:07.509 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  554. 28.10 13:57:07.517 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 8 [ms]
  555. 28.10 13:57:07.545 TRACE [ActionsFilesReader] no new files; last id = 85909
  556. 28.10 13:57:07.545 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  557. 28.10 13:57:16.830 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  558. 28.10 13:57:16.843 TRACE [FileReader] getting new file..
  559. 28.10 13:57:16.869 TRACE [FileReader] No new file
  560. 28.10 13:57:16.870 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  561. 28.10 13:57:17.545 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  562. 28.10 13:57:17.587 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 42 [ms]
  563. 28.10 13:57:17.602 TRACE [ActionsFilesReader] no new files; last id = 85909
  564. 28.10 13:57:17.603 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  565. 28.10 13:57:20.509 DEBUG [TechProcessImpl] Server online mode
  566. 28.10 13:57:26.878 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  567. 28.10 13:57:26.884 TRACE [FileReader] getting new file..
  568. 28.10 13:57:26.894 TRACE [FileReader] No new file
  569. 28.10 13:57:26.894 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  570. 28.10 13:57:27.605 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  571. 28.10 13:57:27.609 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 4 [ms]
  572. 28.10 13:57:27.614 TRACE [ActionsFilesReader] no new files; last id = 85909
  573. 28.10 13:57:27.615 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
  574. 28.10 13:57:27.824 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
  575. 28.10 13:57:27.826 INFO  [CashConfigurationUpdateChecker] Founded server ip: 172.29.17.29
  576. 28.10 13:57:27.827 INFO  [CashConfigurationUpdateChecker] Timeout: 20000
  577. 28.10 13:57:28.098 INFO  [CashConfigurationUpdateChecker] Send message:
  578. 28.10 13:57:28.192 INFO  [CashConfigurationUpdateChecker] Received patches list: []
  579. 28.10 13:57:28.225 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
  580. 28.10 13:57:28.226 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
  581. 28.10 13:57:34.784 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Queue returned null
  582. 28.10 13:57:34.786 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Queue has no items, returning to polling.
  583. 28.10 13:57:34.786 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Polling...
  584. 28.10 13:57:34.786 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
  585. 28.10 13:57:34.817 INFO  [PendingOperationQueue] No pending card operations found.
  586. 28.10 13:57:36.914 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
  587. 28.10 13:57:36.915 TRACE [FileReader] getting new file..
  588. 28.10 13:57:36.925 TRACE [FileReader] No new file
  589. 28.10 13:57:36.925 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
  590. 28.10 13:57:37.624 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
  591. 28.10 13:57:37.626 TRACE [HibernateBackedActionsTransportAuxiliariesDao] leaving getLastDiscountId(). The result is: last-discount-id [disc-id: 85909; sent-to-server: true; saved: true]; It took 2 [ms]
  592. 28.10 13:57:37.631 TRACE [ActionsFilesReader] no new files; last id = 85909
  593. 28.10 13:57:37.631 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
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!