28.10 13:52:57.466 TRACE [HibernateBackedCashAdvertisingActionDao] building hibernate session factory
28.10 13:53:00.587 TRACE [JdbcBackedCashAdvertisingActionDao] leaving postConstruct()
28.10 13:53:11.027 TRACE [AdvActionsCacheImpl] starting AdvActionsCacheImpl initialization in a separate thread
28.10 13:53:11.082 TRACE [AdvActionsCacheImpl] reading all active actions..
28.10 13:53:11.083 TRACE [AdvActionsCacheImpl] initActionsCache: lock on cache was obtained in 0 [ms]
28.10 13:53:11.101 TRACE [AdvActionsCacheImpl] clearing cache..
28.10 13:53:11.101 TRACE [AdvActionsCacheImpl] cache cleared
28.10 13:53:11.102 TRACE [AdvActionsCacheImpl] entering initActionsCacheComplete()
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
28.10 13:53:11.404 TRACE [ActionIntrospectorImpl] <ActionIntrospector> was registered!
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'"
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]
28.10 13:53:14.088 TRACE [JdbcBackedCashAdvertisingActionDao] actions (withou collections) were extracted in 2855 [ms]
28.10 13:53:14.184 TRACE [JdbcBackedCashAdvertisingActionDao] entering pullCollections(Collection). The argument is: actions [size: 139]
28.10 13:53:16.128 TRACE [JdbcBackedCashAdvertisingActionDao] plugins were extracted and mapped in 1054 [ms]
28.10 13:53:17.093 TRACE [JdbcBackedCashAdvertisingActionDao] plugins properties were extracted and mapped in 963 [ms]
28.10 13:53:20.302 TRACE [HibernateBackedCashAdvertisingActionDao] hibernate session factory was built in 22832 [ms]
28.10 13:53:20.863 TRACE [JdbcBackedCashAdvertisingActionDao] master actions were extracted and mapped in 3769 [ms]
28.10 13:53:21.910 TRACE [JdbcBackedCashAdvertisingActionDao] result types were mapped in and mapped 1046 [ms]
28.10 13:53:21.996 TRACE [EventActionsServiceImpl] entering init()
28.10 13:53:22.017 INFO  [EventActionsServiceImpl] updating settings!
28.10 13:53:22.062 TRACE [EventActionsServiceImpl] entering readLocalSettingsIntoObject()
28.10 13:53:22.126 TRACE [JdbcBackedCashAdvertisingActionDao] no labels were extracted
28.10 13:53:22.126 TRACE [JdbcBackedCashAdvertisingActionDao] leaving pullCollections(Collection). It took 7944 [ms]
28.10 13:53:22.166 TRACE [JdbcBackedCashAdvertisingActionDao] leaving getActionsByGuids(Collection, Date). The result size is: 139; it took 11063 [ms]
28.10 13:53:25.456 TRACE [EventActionsServiceImpl] leaving readLocalSettingsIntoObject(). the result is: ru.crystals.pos.loyalty.EventActionsConnectionSettings@1f3c17e
28.10 13:53:25.718 TRACE [EventActionsServiceImpl] settings were reloaded. The result is: ru.crystals.pos.loyalty.EventActionsConnectionSettings@1f3c17e
28.10 13:53:25.721 TRACE [EventActionsServiceImpl] leaving init()
28.10 13:53:26.968 INFO  [CommonLogger] (NixNativeUtils) ADD NTP server
28.10 13:53:26.977 INFO  [CommonLogger] Executing command "sudo mv ntp.sh /opt/ntp.sh"...
28.10 13:53:27.401 INFO  [CommonLogger] Waiting "sudo mv ntp.sh /opt/ntp.sh" command to execute...
28.10 13:53:27.547 INFO  [CommonLogger] Process exited with code 0
28.10 13:53:27.574 INFO  [CommonLogger] Command response: 
28.10 13:53:27.574 INFO  [CommonLogger] Executing command "sudo /opt/ntp.sh"...
28.10 13:53:27.606 INFO  [CommonLogger] Waiting "sudo /opt/ntp.sh" command to execute...
28.10 13:53:27.636 INFO  [CommonLogger] Process exited with code 1
28.10 13:53:27.636 INFO  [CommonLogger] Command response: 
28.10 13:53:27.644 INFO  [CommonLogger] Executing command "sudo chmod u+x /opt/ntp.sh"...
28.10 13:53:27.665 INFO  [CommonLogger] Waiting "sudo chmod u+x /opt/ntp.sh" command to execute...
28.10 13:53:27.666 INFO  [CommonLogger] Process exited with code 0
28.10 13:53:27.666 INFO  [CommonLogger] Command response: 
28.10 13:53:27.666 INFO  [CommonLogger] Executing command "cash save"...
28.10 13:53:27.748 INFO  [CommonLogger] Waiting "cash save" command to execute...
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!
java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
	at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
	at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
28.10 13:53:27.750 ERROR [ActionPluginSerializer] failed to deserialize plugin
java.lang.IllegalArgumentException: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:300) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
Caused by: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
	at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
	at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
	... 11 more
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?
28.10 13:53:28.502 INFO  [CommonLogger] Process exited with code 0
28.10 13:53:30.534 INFO  [CommonLogger] Command response: 
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!
java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
	at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
	at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
28.10 13:53:32.311 ERROR [ActionPluginSerializer] failed to deserialize plugin
java.lang.IllegalArgumentException: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:300) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
Caused by: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
	at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
	at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
	... 11 more
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?
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!
java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
	at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
	at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
28.10 13:53:32.664 ERROR [ActionPluginSerializer] failed to deserialize plugin
java.lang.IllegalArgumentException: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:300) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystalservice.setv6.discounts.utils.ActionPluginSerializer.restorePlugin(ActionPluginSerializer.java:89) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.discounts.AdvertisingActionEntity.getDeserializedPlugins(AdvertisingActionEntity.java:629) ~[DataStructsModule.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.validateAction(AdvActionsCacheImpl.java:440) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.getInvalidActions(AdvActionsCacheImpl.java:414) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.putActionsIntoCacheAndRemoveInvalidOnes(AdvActionsCacheImpl.java:392) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCacheComplete(AdvActionsCacheImpl.java:220) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.initActionsCache(AdvActionsCacheImpl.java:206) ~[loyalty-cash.jar:10.2.75.0]
	at ru.crystals.pos.loyal.cash.service.AdvActionsCacheImpl.lambda$postConstruct$0(AdvActionsCacheImpl.java:71) ~[loyalty-cash.jar:10.2.75.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_112]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
Caused by: java.lang.ClassNotFoundException: ru.crystalservice.setv6.discounts.plugins.UpdateCounterActionResult
	at java.net.URLClassLoader.findClass(URLClassLoader.java:381) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_112]
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) ~[?:1.8.0_112]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_112]
	at java.lang.Class.forName0(Native Method) ~[?:1.8.0_112]
	at java.lang.Class.forName(Class.java:264) ~[?:1.8.0_112]
	at ru.crystalservice.setv6.discounts.utils.PluginPropertiesSerializer.restoreObject(PluginPropertiesSerializer.java:254) ~[DataStructsModule.jar:10.2.75.0]
	... 11 more
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?
28.10 13:53:33.423 TRACE [AdvActionsCacheImpl] leaving initActionsCacheComplete(). it took 22321 [ms]
28.10 13:53:33.423 INFO  [AdvActionsCacheImpl] Time of init actions cache: 22340 ms
28.10 13:53:56.842 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
28.10 13:53:57.392 INFO  [TransferManager] Nothing yet not processed on server to resend
28.10 13:53:58.556 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
28.10 13:53:58.665 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 1834 [ms]
28.10 13:54:34.166 TRACE [SMServiceImpl] entering init()
28.10 13:54:35.513 DEBUG [FileReader] Start FileTransportReader OPERDAY_TO_CASH
28.10 13:54:35.522 TRACE [FileReader] creating instance of FileTransferManager
28.10 13:54:35.525 TRACE [FileReader] create & schedule timer
28.10 13:54:35.528 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:54:35.536 TRACE [MLServiceImpl] entering init()
28.10 13:54:35.538 INFO  [MLServiceImpl] updating settings!
28.10 13:54:35.557 TRACE [MLServiceImpl] entering readLocalSettingsIntoObject()
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]
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
28.10 13:54:35.704 TRACE [MLServiceImpl] leaving init()
28.10 13:54:35.805 TRACE [SCService] entering init()
28.10 13:54:35.807 INFO  [SCService] updating settings!
28.10 13:54:35.808 TRACE [SCService] entering readLocalSettingsIntoObject()
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]
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
28.10 13:54:35.847 INFO  [SCService] looking up LoyFeedbackDao...
28.10 13:54:35.847 TRACE [SCService] leaving init()
28.10 13:54:36.638 INFO  [FiscalPrinterProxy] Try start provider for inn: null
28.10 13:54:36.690 INFO  [FiscalPrinter] Manual Exception has been restored. Exception has been canceled
28.10 13:54:36.889 DEBUG [AbstractFiscalPrinterEmulator] eth0
28.10 13:54:36.889 DEBUG [AbstractFiscalPrinterEmulator] InetAddress: 172.29.17.13
28.10 13:54:36.891 DEBUG [AbstractFiscalPrinterEmulator] java.rmi.server.hostname: 172.29.17.13
28.10 13:54:37.368 INFO  [AbstractFiscalPrinterEmulator] RMI Listening port: 8890
28.10 13:54:37.407 INFO  [FiscalPrinter] ---- FISCAL MODULE START ---- INN null -> true
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
28.10 13:54:37.653 INFO  [FiscalPrinter] Set requisites for inn: 7802781104
28.10 13:54:37.694 INFO  [FiscalPrinter] Set requisites - shop name: jr. name
28.10 13:54:37.695 INFO  [FiscalPrinter] Set requisites - shop address: 199100, Spb, Savushkina, 112
28.10 13:54:40.325 INFO  [FiscalPrinter] getRegNum
28.10 13:54:40.326 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
28.10 13:54:47.867 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:54:47.989 TRACE [FileReader] getting new file..
28.10 13:54:48.026 TRACE [FileReader] No new file
28.10 13:54:48.026 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:54:54.807 TRACE [SoftCheckService] entering init()
28.10 13:54:54.812 INFO  [SoftCheckService] updating settings!
28.10 13:54:54.821 TRACE [SoftCheckService] entering readLocalSettingsIntoObject()
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]
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]
28.10 13:54:55.077 TRACE [SoftCheckService] leaving init()
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]
28.10 13:54:58.042 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:54:58.174 TRACE [FileReader] getting new file..
28.10 13:54:58.256 TRACE [FileReader] No new file
28.10 13:54:58.256 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:54:58.295 INFO  [SetApiShiftEventListener] class ru.crystals.pos.techprocess.SetApiShiftEventListener init method called
28.10 13:54:58.730 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
28.10 13:55:04.036 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
28.10 13:55:04.398 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 5669 [ms]
28.10 13:55:08.344 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:55:08.356 TRACE [FileReader] getting new file..
28.10 13:55:08.416 TRACE [FileReader] No new file
28.10 13:55:08.416 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:55:11.069 ERROR [CashMachinePaymentController] Fail to get cash machine inventory. Cash machine is not initialized.
28.10 13:55:11.156 INFO  [CashMachinePaymentController] denomination auto detected value is 1
28.10 13:55:14.983 INFO  [PaymentsServiceImpl] Add external payment plugin: foo.service.payment
28.10 13:55:17.418 INFO  [CommonLogger] ---{ START OF MODULE }---
28.10 13:55:17.860 INFO  [KeyboardConfigLoader] Keyboard loaded - qwerty , config/plugins/keyboard-qwerty-0-kbd.xml
28.10 13:55:18.226 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.226 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.226 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.227 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.228 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.229 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.230 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.230 WARN  [KeyboardLayoutLoader] Element kbdAlphaNumeric/Ch of keyboard layout is empty
28.10 13:55:18.604 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:55:18.670 TRACE [FileReader] getting new file..
28.10 13:55:18.738 TRACE [FileReader] No new file
28.10 13:55:18.865 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:55:19.221 INFO  [FiscalPrinter] getFactoryNum
28.10 13:55:19.226 INFO  [FiscalPrinter] FactoryNum = 0000033881
28.10 13:55:19.227 INFO  [FiscalPrinter] getRegNum
28.10 13:55:19.228 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
28.10 13:55:19.228 INFO  [FiscalPrinter] getEklzNum
28.10 13:55:19.229 INFO  [FiscalPrinter] EklzNum = 6de03059-181e-4147-b738-705af76216f2
28.10 13:55:19.255 DEBUG [TechProcessImpl] Server online mode
28.10 13:55:19.309 INFO  [FiscalPrinter] getVerBios
28.10 13:55:19.310 INFO  [FiscalPrinter] VerBios = 27
28.10 13:55:19.179 ERROR [ExternalEncryptedEventPacket] Thread-46	Ошибка расшифровки пакета
java.security.InvalidKeyException: Unwrapping failed
	at com.sun.crypto.provider.RSACipher.engineUnwrap(RSACipher.java:445) ~[sunjce_provider.jar:1.8.0_112]
	at javax.crypto.Cipher.unwrap(Cipher.java:2550) ~[?:1.8.0_121]
	at ru.crystals.pos.prismabridge.external.ExternalPacketCipher.encryptAesKey(ExternalPacketCipher.java:57) ~[prismaBridge.jar:10.2.75.0]
	at ru.crystals.pos.prismabridge.external.ExternalPacketCipher.decode(ExternalPacketCipher.java:48) ~[prismaBridge.jar:10.2.75.0]
	at ru.crystals.pos.prismabridge.external.ExternalEncryptedEventPacket.parseEvent(ExternalEncryptedEventPacket.java:44) [prismaBridge.jar:10.2.75.0]
	at ru.crystals.pos.emulator.prisma.PrismaEmulatorRunnable.decodePacket(PrismaEmulatorRunnable.java:168) [PrismaEmulator.jar:?]
	at ru.crystals.pos.emulator.prisma.PrismaEmulatorRunnable.readBytes(PrismaEmulatorRunnable.java:91) [PrismaEmulator.jar:?]
	at ru.crystals.pos.emulator.prisma.PrismaEmulatorRunnable.run(PrismaEmulatorRunnable.java:71) [PrismaEmulator.jar:?]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112]
Caused by: javax.crypto.BadPaddingException: Decryption error
	at sun.security.rsa.RSAPadding.unpadV15(RSAPadding.java:380) ~[?:1.8.0_112]
	at sun.security.rsa.RSAPadding.unpad(RSAPadding.java:291) ~[?:1.8.0_112]
	at com.sun.crypto.provider.RSACipher.doFinal(RSACipher.java:363) ~[sunjce_provider.jar:1.8.0_112]
	at com.sun.crypto.provider.RSACipher.engineUnwrap(RSACipher.java:440) ~[sunjce_provider.jar:1.8.0_112]
	... 8 more
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} ----
28.10 13:55:19.422 INFO  [FiscalPrinter] getRegNum
28.10 13:55:19.423 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
28.10 13:55:19.423 INFO  [FiscalPrinter] getShiftNumber
28.10 13:55:19.425 INFO  [FiscalPrinter] ShiftNumber = 5
28.10 13:55:19.426 INFO  [FiscalPrinter] isShiftOpen
28.10 13:55:19.427 INFO  [FiscalPrinter] getLastKpk
28.10 13:55:19.428 INFO  [FiscalPrinter] LastKpk = 7
28.10 13:55:19.429 INFO  [FiscalPrinter] getCountCashIn
28.10 13:55:19.429 INFO  [FiscalPrinter] CountCashIn = 0
28.10 13:55:19.429 INFO  [FiscalPrinter] getCountCashOut
28.10 13:55:19.429 INFO  [FiscalPrinter] CountCashOut = 0
28.10 13:55:19.429 INFO  [FiscalPrinter] getCountAnnul
28.10 13:55:19.429 INFO  [FiscalPrinter] CountAnnul = 0
28.10 13:55:19.430 INFO  [FiscalPrinter] getSPND
28.10 13:55:19.430 INFO  [FiscalPrinter] CountSPND = 11
28.10 13:55:19.430 INFO  [FiscalPrinter] getCashAmount
28.10 13:55:19.430 INFO  [FiscalPrinter] CashAmount = 14166
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>]
28.10 13:55:19.565 TRACE [TechProcessShift] entering getLastShift()
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]
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}
28.10 13:55:23.539 INFO  [TechProcessShift] Смены совпадают, ожидается синхронизация по документам и счетчикам.
28.10 13:55:23.541 INFO  [TechProcessShift] Счетчики смен совпадают.
28.10 13:55:23.549 INFO  [TechProcessShift] Синхронизация пройдена.
28.10 13:55:23.683 WARN  [SessionNormalizer] Last session id=720 has not been end properly (no end date)
28.10 13:55:23.822 INFO  [SessionNormalizer] Last session end time will be set from lastWorkTime (2019-10-28T13:51:10)
28.10 13:55:23.959 INFO  [TransferManager] OperDayMessanger - UserLogOut
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]
28.10 13:55:24.485 TRACE [CheckService] entering restoreNonFiscalChecks()
28.10 13:55:24.490 WARN  [CheckService] restoring non-fiscalized receipt [id: 680]
28.10 13:55:24.490 TRACE [CheckService] entering setCheckToWork(Long, boolean). the arguments are: idPurchase [680], notifyListeners [true]
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]
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]
28.10 13:55:24.665 TRACE [TechProcessImpl] leaving updateCheck(PurchaseEntity, int)
28.10 13:55:24.666 TRACE [CheckService] leaving setCheckToWork(Long, boolean)
28.10 13:55:24.666 TRACE [CheckService] leaving restoreNonFiscalChecks()
28.10 13:55:25.586 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00818]
28.10 13:55:25.649 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00515]
28.10 13:55:25.653 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00616]
28.10 13:55:25.655 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00888]
28.10 13:55:25.658 TRACE [TechProcessImpl] fillProductEntity: ProductEntity was found by marking [00919]
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]]
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
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!
28.10 13:55:26.557 TRACE [TechProcessShift] entering TP.findNotCommitedChecks()
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]
28.10 13:55:26.579 TRACE [TechProcessShift] leaving TP.findNotCommitedChecks()
28.10 13:55:26.635 TRACE [KeyboardImpl] creating KLocker. timeout = 20 [ms], contact-bounce-time = 100 [ms]
28.10 13:55:30.058 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:55:30.666 TRACE [FileReader] getting new file..
28.10 13:55:31.030 TRACE [FileReader] No new file
28.10 13:55:31.033 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:55:34.405 INFO  [SetApiLoyaltyPluginBackgroundWorker] Cards pending operation sender started
28.10 13:55:34.411 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Polling...
28.10 13:55:34.411 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
28.10 13:55:34.768 INFO  [PendingOperationQueue] No pending card operations found.
28.10 13:55:34.981 INFO  [SetApiPluginLoyProvider] class ru.crystals.pos.loyal.SetApiPluginLoyProvider started
28.10 13:55:40.411 DEBUG [HibernateBackedActionsTransportAuxiliariesDao] building hibernate session factory
28.10 13:55:40.616 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:55:41.038 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:55:41.040 TRACE [FileReader] getting new file..
28.10 13:55:41.177 TRACE [FileReader] No new file
28.10 13:55:41.178 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:55:41.262 TRACE [JdbcBackedLoyFeedbackDao] entering postConstruct()
28.10 13:55:41.264 INFO  [JdbcBackedLoyFeedbackDao] creating jdbcMapper...
28.10 13:55:42.287 TRACE [JdbcBackedLoyFeedbackDao] leaving postConstruct()
28.10 13:55:42.775 TRACE [AbstractCleaner] entering start()
28.10 13:55:42.786 INFO  [AbstractCleaner] <InternalCashPoolExecutor> was added. Starting the cleaner thread
28.10 13:55:42.883 INFO  [AbstractCleaner] cleaner thread was scheduled [initial-delay: 30; interval: 3600; to-remove-at-once: 1000]
28.10 13:55:42.884 TRACE [AbstractCleaner] leaving start()
28.10 13:55:43.144 TRACE [AbstractCleaner] entering start()
28.10 13:55:43.144 INFO  [AbstractCleaner] <InternalCashPoolExecutor> was added. Starting the cleaner thread
28.10 13:55:43.534 INFO  [AbstractCleaner] cleaner thread was scheduled [initial-delay: 30; interval: 3600; to-remove-at-once: 1000]
28.10 13:55:43.539 TRACE [AbstractCleaner] leaving start()
28.10 13:55:49.260 DEBUG [TechProcessImpl] Server online mode
28.10 13:55:50.678 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
28.10 13:55:50.850 INFO  [CommonLogger] Executing command "sudo test-pcx"...
28.10 13:55:51.214 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:55:51.367 TRACE [FileReader] getting new file..
28.10 13:55:51.381 INFO  [CommonLogger] Waiting "sudo test-pcx" command to execute...
28.10 13:55:51.481 TRACE [FileReader] No new file
28.10 13:55:51.483 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:55:52.888 INFO  [CommonLogger] Process exited with code 0
28.10 13:55:52.937 INFO  [CommonLogger] Command response: 
28.10 13:55:52.938 INFO  [CommonLogger] ----Разбор аргументов командной строки-----------
28.10 13:55:52.938 INFO  [CommonLogger] Демонстрационный тест выполнения операций через PCX 
28.10 13:55:52.938 INFO  [CommonLogger] Будут выполнены : 
28.10 13:55:52.938 INFO  [CommonLogger]   - эхо запрос к ПЦ
28.10 13:55:52.938 INFO  [CommonLogger]   - запрос состояния счета бонусной карты
28.10 13:55:52.938 INFO  [CommonLogger]   - оплата товара баллами
28.10 13:55:52.938 INFO  [CommonLogger]   - операция начисления баллов
28.10 13:55:52.938 INFO  [CommonLogger]   - отмена операции оплаты баллов
28.10 13:55:52.938 INFO  [CommonLogger]   - отмена операции начисления баллов
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]
28.10 13:55:52.938 INFO  [CommonLogger] ----Инициализация PCX----------------------------------------------
28.10 13:55:52.938 INFO  [CommonLogger] Executing command "test-pcx"...
28.10 13:55:53.188 INFO  [CommonLogger] Waiting "test-pcx" command to execute...
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]
28.10 13:55:53.846 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:55:53.846 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:55:54.276 INFO  [CommonLogger] Process exited with code 0
28.10 13:55:54.277 INFO  [CommonLogger] Command response: 
28.10 13:55:54.277 INFO  [CommonLogger] ----Разбор аргументов командной строки-----------
28.10 13:55:54.277 INFO  [CommonLogger] Демонстрационный тест выполнения операций через PCX 
28.10 13:55:54.277 INFO  [CommonLogger] Будут выполнены : 
28.10 13:55:54.277 INFO  [CommonLogger]   - эхо запрос к ПЦ
28.10 13:55:54.277 INFO  [CommonLogger]   - запрос состояния счета бонусной карты
28.10 13:55:54.278 INFO  [CommonLogger]   - оплата товара баллами
28.10 13:55:54.278 INFO  [CommonLogger]   - операция начисления баллов
28.10 13:55:54.278 INFO  [CommonLogger]   - отмена операции оплаты баллов
28.10 13:55:54.278 INFO  [CommonLogger]   - отмена операции начисления баллов
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]
28.10 13:55:54.278 INFO  [CommonLogger] ----Инициализация PCX----------------------------------------------
28.10 13:55:54.278 INFO  [CommonLogger] Объект PCX создан !
28.10 13:55:55.192 ERROR [CFTBridgeImpl] Error loading CFT bridge module: Ошибка инициализации SSL: 
28.10 13:55:58.014 INFO  [TransferManager] Nothing yet not processed on server to resend
28.10 13:55:59.704 INFO  [CommonLogger] Executing command "sudo test-pcx"...
28.10 13:55:59.839 INFO  [CommonLogger] Waiting "sudo test-pcx" command to execute...
28.10 13:56:01.073 INFO  [CommonLogger] Process exited with code 0
28.10 13:56:01.112 INFO  [CommonLogger] Command response: 
28.10 13:56:01.112 INFO  [CommonLogger] ----Разбор аргументов командной строки-----------
28.10 13:56:01.112 INFO  [CommonLogger] Демонстрационный тест выполнения операций через PCX 
28.10 13:56:01.129 INFO  [CommonLogger] Будут выполнены : 
28.10 13:56:01.129 INFO  [CommonLogger]   - эхо запрос к ПЦ
28.10 13:56:01.129 INFO  [CommonLogger]   - запрос состояния счета бонусной карты
28.10 13:56:01.129 INFO  [CommonLogger]   - оплата товара баллами
28.10 13:56:01.129 INFO  [CommonLogger]   - операция начисления баллов
28.10 13:56:01.129 INFO  [CommonLogger]   - отмена операции оплаты баллов
28.10 13:56:01.129 INFO  [CommonLogger]   - отмена операции начисления баллов
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]
28.10 13:56:01.129 INFO  [CommonLogger] ----Инициализация PCX----------------------------------------------
28.10 13:56:01.132 INFO  [CommonLogger] Executing command "test-pcx"...
28.10 13:56:01.175 INFO  [CommonLogger] Waiting "test-pcx" command to execute...
28.10 13:56:01.604 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:56:01.734 TRACE [FileReader] getting new file..
28.10 13:56:01.819 TRACE [FileReader] No new file
28.10 13:56:01.821 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:56:02.662 INFO  [CommonLogger] Process exited with code 0
28.10 13:56:02.749 INFO  [CommonLogger] Command response: 
28.10 13:56:03.444 ERROR [CFTBridgeImpl] Error loading CFT bridge module: Ошибка инициализации SSL: 
28.10 13:56:03.850 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:56:04.025 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:56:04.027 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:56:04.742 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
28.10 13:56:05.185 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
28.10 13:56:05.186 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 444 [ms]
28.10 13:56:11.833 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:56:11.852 TRACE [FileReader] getting new file..
28.10 13:56:11.862 TRACE [FileReader] No new file
28.10 13:56:11.863 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:56:12.902 TRACE [LoyTxCleanerWorkhorse] entering run()
28.10 13:56:12.906 INFO  [LoyTxCleanerWorkhorse] shopNo: 3388
28.10 13:56:12.906 INFO  [LoyTxCleanerWorkhorse] cashNo: 1
28.10 13:56:12.906 INFO  [LoyTxCleanerWorkhorse] shiftsToKeep: 0
28.10 13:56:12.907 INFO  [LoyTxCleanerWorkhorse] inn: 7802781104
28.10 13:56:12.908 TRACE [LoyTxCleanerWorkhorse] leaving run(): seems the feature (trim-off superfluous docs) is disabled. shifts-to-keep: 0
28.10 13:56:13.535 TRACE [ActionsCleanerWorkhorse] entering run()
28.10 13:56:13.536 INFO  [ActionsCleanerWorkhorse] looking up <LoyTxDao>
28.10 13:56:13.539 TRACE [JdbcBackedCashAdvertisingActionDao] entering removeStaleActions(int). The argument maxRecordsToRemoveAtOnce is: 1000
28.10 13:56:14.038 TRACE [JdbcBackedCashAdvertisingActionDao] leaving removeStaleActions(int). The result deleted is: 0; it took 500 [ms]
28.10 13:56:14.039 TRACE [ActionsCleanerWorkhorse] leaving run(), removed 0 stale actions
28.10 13:56:14.033 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:56:14.117 INFO  [AeroflotBonusesServiceImpl] --- Start service ---
28.10 13:56:14.131 INFO  [AeroflotBonusesServiceImpl] updating settings!
28.10 13:56:14.132 TRACE [AeroflotBonusesServiceImpl] entering readLocalSettingsIntoObject()
28.10 13:56:14.136 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:56:14.137 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
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'}
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'}
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'
28.10 13:56:14.471 ERROR [AeroflotBonusesWsClient] Unable to load certificate: file "modules/aeroflotBonusesCFT/CFT.pfx" is not found
28.10 13:56:20.318 DEBUG [TechProcessImpl] Server online mode
28.10 13:56:21.969 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:56:21.993 TRACE [FileReader] getting new file..
28.10 13:56:22.002 TRACE [FileReader] No new file
28.10 13:56:22.065 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:56:23.417 INFO  [AeroflotBonusesWsClient] Client successfully rebuild by url = 'http://127.0.0.1:50052/CFTAeroflotBonuses', timeout = '10000000'
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'}
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]
28.10 13:56:23.654 DEBUG [SiebelServiceImpl] create ws-client..
28.10 13:56:23.709 DEBUG [SiebelServiceImpl] register SiebelService in BundleManager..
28.10 13:56:23.731 DEBUG [SiebelServiceImpl] Registered
28.10 13:56:24.138 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:56:24.630 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:56:24.635 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:56:24.863 INFO  [ConfiguratorCashClient] Current version: 10.2.75.0, topologyAddress: 1.0.3388.1, cashType: POS
28.10 13:56:24.888 INFO  [ConfiguratorCashClient] Initialized topologyPoint: ConfigurationTopologyPoint {
  type=POS, 
  topologyAddress=1.0.3388.1, 
  status=IN_WORK, 
  currentVersion=10.2.75.0, 
  previousVersion=, 
  planningVersion=, 
  topologyPointIP=172.29.17.13, 
  updateTime=null, 
  needMakeDbBackup=true, 
  needAutomaticRestart=null, 
  shiftMustBeClosed=false, 
  waitUpdateCommand=false, 
  localPatches=null, 
  online=false}
28.10 13:56:24.891 INFO  [ConfiguratorCashClient] Updates path /mnt/sda1/tce/storage/crystal-conf/updates
28.10 13:56:27.794 INFO  [CashConfigurationUpdateChecker] Waiting cdl...
28.10 13:56:27.821 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
28.10 13:56:28.009 INFO  [CommonLogger] POS loaded in 307 sec
28.10 13:56:32.116 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:56:32.141 TRACE [FileReader] getting new file..
28.10 13:56:32.210 TRACE [FileReader] No new file
28.10 13:56:32.215 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:56:34.636 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:56:34.834 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:56:34.837 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:56:45.432 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:56:45.432 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
28.10 13:56:46.191 TRACE [FileReader] getting new file..
28.10 13:56:46.300 TRACE [FileReader] No new file
28.10 13:56:46.306 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
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]
28.10 13:56:46.440 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:56:46.442 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:56:47.222 INFO  [CommonLogger] Time of starting visualization = 26 ms, totalMemory = 236781568, maxMemory = 259522560, freeMemory = 89668336
28.10 13:56:49.250 INFO  [DocumentSender] ping = true
28.10 13:56:49.480 INFO  [TransferManager] Message [userLogOut] has been sent
28.10 13:56:50.505 DEBUG [TechProcessImpl] Server online mode
28.10 13:56:52.245 INFO  [FiscalPrinter] getFactoryNum
28.10 13:56:52.249 INFO  [FiscalPrinter] FactoryNum = 0000033881
28.10 13:56:52.249 INFO  [FiscalPrinter] getRegNum
28.10 13:56:52.314 INFO  [FiscalPrinter] RegNum = NFM.3388.1.0.1571827454607
28.10 13:56:52.315 INFO  [FiscalPrinter] getEklzNum
28.10 13:56:52.315 INFO  [FiscalPrinter] EklzNum = 6de03059-181e-4147-b738-705af76216f2
28.10 13:56:52.316 INFO  [FiscalPrinter] getVerBios
28.10 13:56:52.316 INFO  [FiscalPrinter] VerBios = 27
28.10 13:56:53.748 TRACE [AeroflotBonusesServiceImpl] Not found pending operations
28.10 13:56:56.316 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:56:56.376 TRACE [FileReader] getting new file..
28.10 13:56:56.433 TRACE [FileReader] No new file
28.10 13:56:56.433 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:56:56.444 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:56:57.508 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:56:57.508 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:56:57.505 TRACE [DocumentSender] entering getDocuments()
28.10 13:56:58.289 TRACE [DocumentSender] leaving getDocuments(). The result size is: 0; it took 791 [ms]
28.10 13:56:58.594 INFO  [TransferManager] OD found 0 documents to register
28.10 13:56:58.882 INFO  [DocumentSender] OD found 0 transactions to register
28.10 13:57:05.223 TRACE [HibernateBackedLoyTxDao] entering getLoyTxesByStatus(Collection, int). The arguments are: statuses [[NO_SENT, WAIT_ACKNOWLEDGEMENT, SENT_ERROR]], maxResults [100]
28.10 13:57:06.725 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:57:06.730 TRACE [FileReader] getting new file..
28.10 13:57:06.823 TRACE [FileReader] No new file
28.10 13:57:06.827 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:57:06.977 TRACE [HibernateBackedLoyTxDao] [0] loy-tx records were extracted from the db
28.10 13:57:06.982 TRACE [HibernateBackedLoyTxDao] leaving getLoyTxesByStatus(Collection, int). The result is: []; it took 1760 [ms]
28.10 13:57:07.509 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:57:07.545 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:57:07.545 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:57:16.830 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:57:16.843 TRACE [FileReader] getting new file..
28.10 13:57:16.869 TRACE [FileReader] No new file
28.10 13:57:16.870 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:57:17.545 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:57:17.602 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:57:17.603 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:57:20.509 DEBUG [TechProcessImpl] Server online mode
28.10 13:57:26.878 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:57:26.884 TRACE [FileReader] getting new file..
28.10 13:57:26.894 TRACE [FileReader] No new file
28.10 13:57:26.894 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:57:27.605 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:57:27.614 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:57:27.615 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.
28.10 13:57:27.824 INFO  [CashConfigurationUpdateChecker] Current status: IN_WORK
28.10 13:57:27.826 INFO  [CashConfigurationUpdateChecker] Founded server ip: 172.29.17.29
28.10 13:57:27.827 INFO  [CashConfigurationUpdateChecker] Timeout: 20000
28.10 13:57:28.098 INFO  [CashConfigurationUpdateChecker] Send message: 
28.10 13:57:28.192 INFO  [CashConfigurationUpdateChecker] Received patches list: []
28.10 13:57:28.225 INFO  [CashConfigurationUpdateChecker] isNeedWaitUpdateCommand: false
28.10 13:57:28.226 INFO  [CashConfigurationUpdateChecker] sleepInt(60000)
28.10 13:57:34.784 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Queue returned null
28.10 13:57:34.786 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Queue has no items, returning to polling.
28.10 13:57:34.786 DEBUG [SetApiLoyaltyPluginBackgroundWorker] Polling...
28.10 13:57:34.786 INFO  [PendingOperationQueue] Pending cards operation queue is empty. Populating from DB...
28.10 13:57:34.817 INFO  [PendingOperationQueue] No pending card operations found.
28.10 13:57:36.914 DEBUG [FileReader] FileTransportReader run "OPERDAY_TO_CASH"
28.10 13:57:36.915 TRACE [FileReader] getting new file..
28.10 13:57:36.925 TRACE [FileReader] No new file
28.10 13:57:36.925 DEBUG [FileReader] Scheduling next call of data type "OPERDAY_TO_CASH" after 10 seconds.
28.10 13:57:37.624 TRACE [HibernateBackedActionsTransportAuxiliariesDao] entering getLastDiscountId()
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]
28.10 13:57:37.631 TRACE [ActionsFilesReader] no new files; last id = 85909
28.10 13:57:37.631 DEBUG [ActionsFilesReader] Scheduling next call of data type "LOY" after 10 seconds.