PHP Warnings im Log

misery · Beitrag von **misery** » So 25. Jul 2021, 18:39

Moin Stefan,

ich hatte die 2.0.25 für lange Zeit installiert und bekam dann eines Tages das Feedback, dass das System nicht mehr erreichbar ist. Ich habe mich eingeloggt und sah, dass mysql und php-fpm etwa 100 % benötigten. Ordersprinter war nicht mehr über Browser zu erreichen. Nach etwa einer Stunde habe ich php-fpm abgewürgt und neu gestartet. Danach ging alles.

Habe dann auf die 2.0.29 aktualisiert, in der Hoffnung, dass das Problem von oben behoben ist. Kannst du das bestätigen?

Nun habe ich aber seit dem Update so einige Fehlermeldungen im Server-Logs

Code: Alles auswählen

[25-Jul-2021 17:38:23] WARNING: [pool www] child 734 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 17:47:19] WARNING: [pool www] child 734 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 17:47:24] WARNING: [pool www] child 731, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=queue&command=declarePaidCreateBillReturnBillId") executing too slow (1.069598 sec), logging
[25-Jul-2021 17:47:24] NOTICE: child 731 stopped for tracing
[25-Jul-2021 17:47:24] NOTICE: about to trace 731
[25-Jul-2021 17:47:24] NOTICE: finished trace of 731
[25-Jul-2021 17:49:26] WARNING: [pool www] child 734, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=queue&command=addProductListToQueue") executing too slow (1.098799 sec), logging
[25-Jul-2021 17:49:26] NOTICE: child 734 stopped for tracing
[25-Jul-2021 17:49:26] NOTICE: about to trace 734
[25-Jul-2021 17:49:26] NOTICE: finished trace of 734
[25-Jul-2021 17:51:02] WARNING: [pool www] child 732 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 17:51:08] WARNING: [pool www] child 731, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=queue&command=declarePaidCreateBillReturnBillId") executing too slow (1.293503 sec), logging
[25-Jul-2021 17:51:08] NOTICE: child 731 stopped for tracing
[25-Jul-2021 17:51:08] NOTICE: about to trace 731
[25-Jul-2021 17:51:08] NOTICE: finished trace of 731
[25-Jul-2021 17:54:05] WARNING: [pool www] child 732 said into stderr: ""
[25-Jul-2021 17:56:05] WARNING: [pool www] child 733 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 17:56:05] WARNING: [pool www] child 731 said into stderr: ""
[25-Jul-2021 17:56:10] WARNING: [pool www] child 734, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=queue&command=declarePaidCreateBillReturnBillId") executing too slow (1.290390 sec), logging
[25-Jul-2021 17:56:10] WARNING: [pool www] child 733, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4932&thr=4&instance=1") executing too slow (1.319612 sec), logging
[25-Jul-2021 17:56:10] NOTICE: child 733 stopped for tracing
[25-Jul-2021 17:56:10] NOTICE: about to trace 733
[25-Jul-2021 17:56:10] NOTICE: finished trace of 733
[25-Jul-2021 17:56:10] NOTICE: child 734 stopped for tracing
[25-Jul-2021 17:56:10] NOTICE: about to trace 734
[25-Jul-2021 17:56:10] NOTICE: finished trace of 734
[25-Jul-2021 17:56:29] WARNING: [pool www] child 733 said into stderr: ""
[25-Jul-2021 17:59:40] WARNING: [pool www] child 734 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 18:10:38] WARNING: [pool www] child 732 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 18:21:07] WARNING: [pool www] child 734, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=roomtables&command=showAllRooms&_=1627229492917") executing too slow (1.228266 sec), logging
[25-Jul-2021 18:21:07] WARNING: [pool www] child 733, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive&_=1627229492916") executing too slow (1.249002 sec), logging
[25-Jul-2021 18:21:07] NOTICE: child 734 stopped for tracing
[25-Jul-2021 18:21:07] NOTICE: about to trace 734
[25-Jul-2021 18:21:07] NOTICE: finished trace of 734
[25-Jul-2021 18:21:07] NOTICE: child 733 stopped for tracing
[25-Jul-2021 18:21:07] NOTICE: about to trace 733
[25-Jul-2021 18:21:07] NOTICE: finished trace of 733
[25-Jul-2021 18:23:04] WARNING: [pool www] child 732 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[25-Jul-2021 18:31:46] WARNING: [pool www] child 731 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"

Ist das etwas gefährliches?

Ich lasse von php-fpm übrigens auch "slow"-Operations loggen.

Code: Alles auswählen

[25-Jul-2021 17:23:40]  [pool www] pid 734
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13e30] execute() /var/www/webapp/php/printqueue.php:209
[0x00007f09d2a13c60] queueWorkPrintJob() /var/www/webapp/php/queuecontent.php:712
[0x00007f09d2a13ac0] createAWorkReceiptAndQueueWorkPrint() /var/www/webapp/php/queuecontent.php:629
[0x00007f09d2a13940] doWorkPrintCore() /var/www/webapp/php/queuecontent.php:596
[0x00007f09d2a13800] doWorkPrint() /var/www/webapp/php/queuecontent.php:1400
[0x00007f09d2a13350] addProductListToQueueCore() /var/www/webapp/php/queuecontent.php:1125
[0x00007f09d2a13250] addProductListToQueue() /var/www/webapp/php/queuecontent.php:86
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:69

[25-Jul-2021 17:47:24]  [pool www] pid 731
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a139f0] execute() /var/www/webapp/php/commonutils.php:374
[0x00007f09d2a13950] execSql() /var/www/webapp/php/bill.php:340
[0x00007f09d2a13800] signValueByTseAndUpdateBill() /var/www/webapp/php/bill.php:296
[0x00007f09d2a13630] signOrdersBill() /var/www/webapp/php/queuecontent.php:2408
[0x00007f09d2a13250] declarePaidCreateBillReturnBillId() /var/www/webapp/php/queuecontent.php:144
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:69

[25-Jul-2021 17:49:26]  [pool www] pid 734
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13c10] file_get_contents() /var/www/webapp/php/utilities/tse.php:112
[0x00007f09d2a13b20] sendToTSEConnector() /var/www/webapp/php/utilities/tse.php:148
[0x00007f09d2a13a10] sendValueToTseForSigning() /var/www/webapp/php/utilities/tse.php:161
[0x00007f09d2a13990] sendOrdersToTSE() /var/www/webapp/php/queuecontent.php:1417
[0x00007f09d2a13800] signAtTSE() /var/www/webapp/php/queuecontent.php:1378
[0x00007f09d2a13350] addProductListToQueueCore() /var/www/webapp/php/queuecontent.php:1125
[0x00007f09d2a13250] addProductListToQueue() /var/www/webapp/php/queuecontent.php:86
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:69

[25-Jul-2021 17:51:08]  [pool www] pid 731
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13630] commit() /var/www/webapp/php/queuecontent.php:2420
[0x00007f09d2a13250] declarePaidCreateBillReturnBillId() /var/www/webapp/php/queuecontent.php:144
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:69

[25-Jul-2021 17:56:10]  [pool www] pid 733
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13460] execute() /var/www/webapp/php/printqueue.php:169
[0x00007f09d2a133a0] saveLastPrintServerAccess() /var/www/webapp/php/printqueue.php:883
[0x00007f09d2a13260] getNextTicketJobs() /var/www/webapp/php/printqueue.php:52
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:87

[25-Jul-2021 17:56:10]  [pool www] pid 734
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13630] commit() /var/www/webapp/php/queuecontent.php:2420
[0x00007f09d2a13250] declarePaidCreateBillReturnBillId() /var/www/webapp/php/queuecontent.php:144
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:69

[25-Jul-2021 18:21:07]  [pool www] pid 734
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13210] session_start() /var/www/webapp/php/roomtables.php:17
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:75

[25-Jul-2021 18:21:07]  [pool www] pid 733
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f09d2a13560] file_get_contents() /var/www/webapp/php/utilities/tse.php:112
[0x00007f09d2a13470] sendToTSEConnector() /var/www/webapp/php/utilities/tse.php:186
[0x00007f09d2a13370] checkTseServerAccesible() /var/www/webapp/php/admin.php:538
[0x00007f09d2a13240] isPrinterServerActive() /var/www/webapp/php/admin.php:455
[0x00007f09d2a13190] handleCommand() /var/www/webapp/php/contenthandler.php:66

Sieht das für dich normal aus?
Ordersprinter läuft als alleinige VM (2 CPUs) auf einer DS220+ mit 6 GB RAM.

Viele Grüße
André

misery · Beitrag von **misery** » Mo 26. Jul 2021, 14:38

Habe das "slow"-Limit mal auf 5 Sekunden angehoben.

Code: Alles auswählen

[26-Jul-2021 12:01:51] WARNING: [pool www] child 3281 said into stderr: ""
[26-Jul-2021 12:18:28] WARNING: [pool www] child 3276, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive") executing too slow (5.210977 sec), logging
[26-Jul-2021 12:18:28] NOTICE: child 3276 stopped for tracing
[26-Jul-2021 12:18:28] NOTICE: about to trace 3276
[26-Jul-2021 12:18:28] NOTICE: finished trace of 3276
[26-Jul-2021 12:18:32] WARNING: [pool www] child 3281, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=admin&command=setLastModuleOfUser") executing too slow (5.047674 sec), logging
[26-Jul-2021 12:18:32] NOTICE: child 3281 stopped for tracing
[26-Jul-2021 12:18:32] NOTICE: about to trace 3281
[26-Jul-2021 12:18:32] NOTICE: finished trace of 3281
[26-Jul-2021 12:18:33] WARNING: [pool www] child 3279, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=admin&command=getmobilecss") executing too slow (6.582918 sec), logging
[26-Jul-2021 12:18:33] NOTICE: child 3279 stopped for tracing
[26-Jul-2021 12:18:33] NOTICE: about to trace 3279
[26-Jul-2021 12:18:33] NOTICE: finished trace of 3279
[26-Jul-2021 12:18:39] WARNING: [pool www] child 3277 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[26-Jul-2021 12:19:20] WARNING: [pool www] child 3278 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[26-Jul-2021 12:19:29] WARNING: [pool www] child 3280 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[26-Jul-2021 12:23:32] WARNING: [pool www] child 3279, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=closing&command=createClosing") executing too slow (5.695081 sec), logging
[26-Jul-2021 12:23:32] NOTICE: child 3279 stopped for tracing
[26-Jul-2021 12:23:32] NOTICE: about to trace 3279
[26-Jul-2021 12:23:32] NOTICE: finished trace of 3279
[26-Jul-2021 12:23:33] WARNING: [pool www] child 3280, script '/var/www/webapp/php/contenthandler.php' (request: "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4932&thr=4&instance=1") executing too slow (5.085451 sec), logging
[26-Jul-2021 12:23:33] NOTICE: child 3280 stopped for tracing
[26-Jul-2021 12:23:33] NOTICE: about to trace 3280
[26-Jul-2021 12:23:33] NOTICE: finished trace of 3280
[26-Jul-2021 12:23:42] WARNING: [pool www] child 3281, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=closing&command=getClosings&month=7&year=2021&_=1627294995049") executing too slow (5.383928 sec), logging
[26-Jul-2021 12:23:42] NOTICE: child 3281 stopped for tracing
[26-Jul-2021 12:23:42] NOTICE: about to trace 3281
[26-Jul-2021 12:23:42] NOTICE: finished trace of 3281
[26-Jul-2021 12:23:43] WARNING: [pool www] child 3279, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=closing&command=getFirstAndLastClosing&_=1627294995050") executing too slow (5.372201 sec), logging
[26-Jul-2021 12:23:43] WARNING: [pool www] child 3277, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=closing&command=getCashSumsForNextClosing&_=1627294995051") executing too slow (5.366571 sec), logging
[26-Jul-2021 12:23:43] WARNING: [pool www] child 3276, script '/var/www/webapp/php/contenthandler.php' (request: "GET /php/contenthandler.php?module=printqueue&command=queueClosingSummary&closingid=226&_=1627294995052") executing too slow (5.365668 sec), logging
[26-Jul-2021 12:23:43] NOTICE: child 3277 stopped for tracing
[26-Jul-2021 12:23:43] NOTICE: about to trace 3277
[26-Jul-2021 12:23:43] NOTICE: finished trace of 3277
[26-Jul-2021 12:23:43] NOTICE: child 3276 stopped for tracing
[26-Jul-2021 12:23:43] NOTICE: about to trace 3276
[26-Jul-2021 12:23:43] NOTICE: finished trace of 3276
[26-Jul-2021 12:23:43] NOTICE: child 3279 stopped for tracing
[26-Jul-2021 12:23:43] NOTICE: about to trace 3279
[26-Jul-2021 12:23:43] NOTICE: finished trace of 3279
[26-Jul-2021 14:04:46] WARNING: [pool www] child 3280 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[26-Jul-2021 14:20:10] WARNING: [pool www] child 3277 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[26-Jul-2021 14:20:21] WARNING: [pool www] child 3278 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"
[26-Jul-2021 14:30:44] WARNING: [pool www] child 3276 said into stderr: "NOTICE: PHP message: SELECT ordersprinter_customers.id as id,ordersprinter_customers.id as object,CONCAT(COALESCE(name,''),' - ',COALESCE(room,'')) as guest  FROM ordersprinter_customers  LEFT JOIN ordersprinter_vacations ON ordersprinter_customers.id=ordersprinter_vacations.customerid  WHERE  ((checkin <= CURDATE()) AND (CURDATE() <= checkout))  OR (checkin is null AND (CURDATE() <= checkout))  OR ((checkin <= CURDATE()) AND checkout is null)  OR (permanent = '1')  GROUP BY id,object,guest"

Code: Alles auswählen

[26-Jul-2021 12:18:28]  [pool www] pid 3276
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413560] file_get_contents() /var/www/webapp/php/utilities/tse.php:112
[0x00007f9834413470] sendToTSEConnector() /var/www/webapp/php/utilities/tse.php:186
[0x00007f9834413370] checkTseServerAccesible() /var/www/webapp/php/admin.php:538
[0x00007f9834413240] isPrinterServerActive() /var/www/webapp/php/admin.php:455
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:66

[26-Jul-2021 12:18:32]  [pool www] pid 3281
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413300] session_start() /var/www/webapp/php/commonutils.php:569
[0x00007f9834413240] checkRights() /var/www/webapp/php/admin.php:186
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:66

[26-Jul-2021 12:18:33]  [pool www] pid 3279
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413300] session_start() /var/www/webapp/php/commonutils.php:569
[0x00007f9834413240] checkRights() /var/www/webapp/php/admin.php:186
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:66

[26-Jul-2021 12:23:32]  [pool www] pid 3279
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f98344137f0] execute() /var/www/webapp/php/commonutils.php:372
[0x00007f9834413750] execSql() /var/www/webapp/php/closing.php:381
[0x00007f9834413330] createClosingCore() /var/www/webapp/php/closing.php:160
[0x00007f9834413230] createClosing() /var/www/webapp/php/closing.php:38
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:84

[26-Jul-2021 12:23:33]  [pool www] pid 3280
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413460] execute() /var/www/webapp/php/printqueue.php:169
[0x00007f98344133a0] saveLastPrintServerAccess() /var/www/webapp/php/printqueue.php:883
[0x00007f9834413260] getNextTicketJobs() /var/www/webapp/php/printqueue.php:52
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:87

[26-Jul-2021 12:23:42]  [pool www] pid 3281
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413660] execute() /var/www/webapp/php/commonutils.php:364
[0x00007f98344135c0] fetchSqlAll() /var/www/webapp/php/commonutils.php:692
[0x00007f9834413490] getMasterDataAtCertainDateTime() /var/www/webapp/php/closing.php:553
[0x00007f9834413230] getClosings() /var/www/webapp/php/closing.php:51
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:84

[26-Jul-2021 12:23:43]  [pool www] pid 3277
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f98344132b0] session_start() /var/www/webapp/php/closing.php:77
[0x00007f9834413230] hasCurrentUserManagerOrAdminRights() /var/www/webapp/php/closing.php:21
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:84

[26-Jul-2021 12:23:43]  [pool www] pid 3276
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f98344133c0] session_start() /var/www/webapp/php/utilities/userrights.php:88
[0x00007f9834413340] hasCurrentUserRight() /var/www/webapp/php/printqueue.php:447
[0x00007f9834413260] queueClosingSummary() /var/www/webapp/php/printqueue.php:105
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:87

[26-Jul-2021 12:23:43]  [pool www] pid 3279
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f98344132b0] session_start() /var/www/webapp/php/closing.php:77
[0x00007f9834413230] hasCurrentUserManagerOrAdminRights() /var/www/webapp/php/closing.php:21
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:84

Ist trotzdem noch relativ oft, oder?

Die DS220+ hat ein Intel Celeron Dual-Kern J4025 @ 2Ghz mit 2,9 Ghz Burst. Sollte doch eigentlich reichen.

André

Beitrag von **pichel** » Di 27. Jul 2021, 19:23

Hallo André,

zunächst einmal war die Aktualisierung auf 2.0.29 bestimmt die Lösung für das Problem, dass mySQL auf 100% ging. Ich speichere die Information über die "Vorgänge", also was durch die TSE signiert werden muss, in einer Tabelle "operations". Darin gebe ich auch einen Teil der Information über die zu signierenden Inhalte. Wenn diese Sonderzeichen enthalten, die sich nicht mit der in MySQL benutzten Implementierung von UTF8 abbilden lassen (MySQL kann nur eine Untermenge von UTF8 managen), kommt es zu einer Exception. An der Stelle habe ich die Exception abgefangen, die dort wegen einer Race-Condition passieren konnte und habe es halt ein weiteres Mal versucht - bis 2.0.28 in einer Endlosschleife. Da ich aber den zweiten Fall (INSERT geht schief wegen nicht verarbeitbarer Argumente) nicht abgefangen hatte, ging der MySQL-Prozess auf max, bis die in der PHP eingestellte max_execution_time dem Spuk ein Ende bereitete. Mit 2.0.29 habe ich da einen Workaround gebaut.

Nun zum Logging. Die Ausgabe der SQL-Query ist erst einmal ein Überbleibsel aus der Entwicklung und tut nicht weh.

Aber warum einige Abfragen mehr als 5 Sekunden benötigen, kann ich mir nicht erklären und kann es auch bei mir nicht reproduzieren. Ich lasse vor jedem Release einen automatischen Test laufen, der die Standard-Operationen durchführt und da bin ich bei wenigen Millisekunden. Ich habe auch sehr große Datenbanken von Anwendern bekommen, über 200 Millisekunden komme ich in der 2.0.29 bei keiner Abfrage bei solchen DBs.

Ausnahmen sind: Starte Produktivbetrieb, Backup, Restore, Erstellung von PDF-Reports

Nun kenne ich mich mit fpm nicht so gut aus, kann es sein, dass es Threads gibt, die in einer Warteschleife warten, bis sie zur Ausführung kommen dürfen und diese Wartezeiten in die Ausführungszeiten hinzuaddiert werden?

Es wäre prinzipiell gar nicht so schwierig, OrderSprinter mit replizierten DBs zu betreuben und damit die Last gleichmäßig zu verteilen. Aber ehrlich glaube ich, dass hier erst mal die Ursache für die vielen Slow-Prozesse gefunden werden muss. Ist denn physikalisch eine HDD oder SSD verbaut? Ich habe ein wenig den Host in Verdacht. Kannst du das gleiche Setup nicht mal ohne Virtualisierung testen und messen, oder alternativ in einem Container?

Gruß,

Stefan

misery · Beitrag von **misery** » Mi 28. Jul 2021, 12:23

pichel hat geschrieben: ↑Di 27. Jul 2021, 19:23 Hallo André,

zunächst einmal war die Aktualisierung auf 2.0.29 bestimmt die Lösung für das Problem, dass mySQL auf 100% ging. Ich speichere die Information über die "Vorgänge", also was durch die TSE signiert werden muss, in einer Tabelle "operations". Darin gebe ich auch einen Teil der Information über die zu signierenden Inhalte. Wenn diese Sonderzeichen enthalten, die sich nicht mit der in MySQL benutzten Implementierung von UTF8 abbilden lassen (MySQL kann nur eine Untermenge von UTF8 managen), kommt es zu einer Exception. An der Stelle habe ich die Exception abgefangen, die dort wegen einer Race-Condition passieren konnte und habe es halt ein weiteres Mal versucht - bis 2.0.28 in einer Endlosschleife. Da ich aber den zweiten Fall (INSERT geht schief wegen nicht verarbeitbarer Argumente) nicht abgefangen hatte, ging der MySQL-Prozess auf max, bis die in der PHP eingestellte max_execution_time dem Spuk ein Ende bereitete. Mit 2.0.29 habe ich da einen Workaround gebaut.

Nun zum Logging. Die Ausgabe der SQL-Query ist erst einmal ein Überbleibsel aus der Entwicklung und tut nicht weh.

Danke, das ist schon mal beruhigend!

Aber warum einige Abfragen mehr als 5 Sekunden benötigen, kann ich mir nicht erklären und kann es auch bei mir nicht reproduzieren. Ich lasse vor jedem Release einen automatischen Test laufen, der die Standard-Operationen durchführt und da bin ich bei wenigen Millisekunden. Ich habe auch sehr große Datenbanken von Anwendern bekommen, über 200 Millisekunden komme ich in der 2.0.29 bei keiner Abfrage bei solchen DBs.

Ausnahmen sind: Starte Produktivbetrieb, Backup, Restore, Erstellung von PDF-Reports

Nun kenne ich mich mit fpm nicht so gut aus, kann es sein, dass es Threads gibt, die in einer Warteschleife warten, bis sie zur Ausführung kommen dürfen und diese Wartezeiten in die Ausführungszeiten hinzuaddiert werden?

Es wäre prinzipiell gar nicht so schwierig, OrderSprinter mit replizierten DBs zu betreuben und damit die Last gleichmäßig zu verteilen. Aber ehrlich glaube ich, dass hier erst mal die Ursache für die vielen Slow-Prozesse gefunden werden muss. Ist denn physikalisch eine HDD oder SSD verbaut? Ich habe ein wenig den Host in Verdacht. Kannst du das gleiche Setup nicht mal ohne Virtualisierung testen und messen, oder alternativ in einem Container?

Da ist eine Seagate Ironwolf 1TB verbaut - also HDD. Das System macht auch sonst nix anderes als Ordersprinter zu managen und Backups / Überwachung zu übernehmen. Die größte Zeit gehen die Anfragen auch unter einer Sekunde so durch. Nur manchmal dauert es länger.

Ordersprinter von VM in den Container packen ist bisschen riskant im laufenden Betrieb. Ich denke auch nicht, dass hier ein System überlastet ist. Wir reden hier von 3,6 MB als mysql dump insgesamt seit letztem Jahr.

php-fpm läuft mit 6 Prozessen gleichzeitig im "static"-Betrieb.

Heutige Ereignisse über 5 Sekunden:

Code: Alles auswählen

[27-Jul-2021 10:49:21]  [pool www] pid 3281
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413560] file_get_contents() /var/www/webapp/php/utilities/tse.php:112
[0x00007f9834413470] sendToTSEConnector() /var/www/webapp/php/utilities/tse.php:186
[0x00007f9834413370] checkTseServerAccesible() /var/www/webapp/php/admin.php:538
[0x00007f9834413240] isPrinterServerActive() /var/www/webapp/php/admin.php:455
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:66

[28-Jul-2021 11:36:20]  [pool www] pid 3280
script_filename = /var/www/webapp/php/updatehandler.php
[0x00007f98344133e0] file_get_contents() /var/www/webapp/php/updater.php:83
[0x00007f9834413280] getInfoFile() /var/www/webapp/php/updater.php:119
[0x00007f98344131a0] getAvailableVersion() /var/www/webapp/php/updater.php:11
[0x00007f98344130b0] handleCommand() /var/www/webapp/php/updatehandler.php:10

[28-Jul-2021 11:36:20]  [pool www] pid 3278
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413300] session_start() /var/www/webapp/php/commonutils.php:569
[0x00007f9834413240] checkRights() /var/www/webapp/php/admin.php:186
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:66

[28-Jul-2021 11:49:34]  [pool www] pid 3281
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413bd0] file_get_contents() /var/www/webapp/php/utilities/tse.php:112
[0x00007f9834413ae0] sendToTSEConnector() /var/www/webapp/php/utilities/tse.php:148
[0x00007f98344139d0] sendValueToTseForSigning() /var/www/webapp/php/utilities/tse.php:158
[0x00007f9834413950] sendNormalBillToTSE() /var/www/webapp/php/bill.php:300
[0x00007f9834413800] signValueByTseAndUpdateBill() /var/www/webapp/php/bill.php:296
[0x00007f9834413630] signOrdersBill() /var/www/webapp/php/queuecontent.php:2408
[0x00007f9834413250] declarePaidCreateBillReturnBillId() /var/www/webapp/php/queuecontent.php:144
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:69

[28-Jul-2021 11:49:39]  [pool www] pid 3277
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007f9834413460] execute() /var/www/webapp/php/printqueue.php:169
[0x00007f98344133a0] saveLastPrintServerAccess() /var/www/webapp/php/printqueue.php:883
[0x00007f9834413260] getNextTicketJobs() /var/www/webapp/php/printqueue.php:52
[0x00007f9834413190] handleCommand() /var/www/webapp/php/contenthandler.php:87

Hier mal das access.log zu den beiden letzten Einträgen

Code: Alles auswählen

[28/Jul/2021:11:49:20 +0200] "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive&_=1627464993794 HTTP/1.1" 200 75 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:20 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:21 +0200] "GET /img/gray.png?t=1627465771955 HTTP/1.1" 200 160 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "GET /php/contenthandler.php?module=admin&command=getPayPrintType&_=1627464993795 HTTP/1.1" 200 34 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn&_=1627464993796 HTTP/1.1" 200 36 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "GET /php/contenthandler.php?module=admin&command=getOrderVolume&_=1627464993797 HTTP/1.1" 200 32 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "GET /php/contenthandler.php?module=admin&command=hasUserPaydeskRight&_=1627464993799 HTTP/1.1" 200 36 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "GET /php/contenthandler.php?module=queue&command=getJsonLongNamesOfProdsForTableNotDelivered&tableid=21&_=1627464993798 HTTP/1.1" 200 247 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:21 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:23 +0200] "GET /img/gray.png?t=1627465773960 HTTP/1.1" 200 160 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /paydesk.html?t=21&v=2.0.29 HTTP/1.1" 200 24713 "http://order.fritz.box/waiter.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /php/contenthandler.php?module=admin&command=getmobilecss HTTP/1.1" 200 39357 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /receiptutils.js?v=2.0.29 HTTP/1.1" 304 0 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /php/contenthandler.php?module=admin&command=getJsonMenuItemsAndVersion HTTP/1.1" 200 298 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /php/contenthandler.php?module=admin&command=getGeneralConfigItems HTTP/1.1" 200 4561 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive HTTP/1.1" 200 75 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /php/contenthandler.php?module=admin&command=getButtonSizes HTTP/1.1" 200 65 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:24 +0200] "GET /php/contenthandler.php?module=admin&command=getPreferimgmobile HTTP/1.1" 200 34 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /php/contenthandler.php?module=admin&command=getPreferCalc HTTP/1.1" 200 32 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /php/contenthandler.php?module=admin&command=getPayments HTTP/1.1" 200 148 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /php/tablemap.php?command=getTableMapPreferences HTTP/1.1" 200 336 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /php/contenthandler.php?module=queue&command=getJsonTableNameFromId&tableid=21 HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /php/contenthandler.php?module=queue&command=getJsonProductsOfTableToPay&tableid=21 HTTP/1.1" 200 244 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:25 +0200] "GET /img/gray.png?t=1627465775713 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:26 +0200] "GET /img/gray.png?t=1627465777721 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:27 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:27 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:27 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:28 +0200] "GET /img/gray.png?t=1627465779721 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:28 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:29 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn&_=1627465775240 HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:43 +0200] "POST /php/contenthandler.php?module=queue&command=declarePaidCreateBillReturnBillId HTTP/1.1" 200 65 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:43 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:44 +0200] "GET /img/gray.png?t=1627465795756 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:44 +0200] "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive&_=1627465775241 HTTP/1.1" 499 0 "http://order.fritz.box/paydesk.html?t=21&v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:44 +0200] "GET /php/contenthandler.php?module=admin&command=getmobilecss HTTP/1.1" 200 39357 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=getJsonMenuItemsAndVersion HTTP/1.1" 200 298 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive HTTP/1.1" 200 75 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=getGeneralConfigItems HTTP/1.1" 200 4561 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=getButtonSizes HTTP/1.1" 200 65 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=getPreferimgmobile HTTP/1.1" 200 34 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=getPreferCalc HTTP/1.1" 200 32 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=getPayments HTTP/1.1" 200 148 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/tablemap.php?command=getTableMapPreferences HTTP/1.1" 200 336 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=roomtables&command=getRooms HTTP/1.1" 200 125 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:45 +0200] "GET /img/gray.png?t=1627465796271 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:47 +0200] "GET /img/gray.png?t=1627465798278 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:47 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:49 +0200] "GET /img/gray.png?t=1627465800277 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:50 +0200] "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive&_=1627465795956 HTTP/1.1" 200 75 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:50 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn&_=1627465795957 HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:50 +0200] "GET /php/contenthandler.php?module=roomtables&command=getUnpaidTables&roomid=2&_=1627465795958 HTTP/1.1" 200 109 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:50 +0200] "GET /php/tablemap.php?command=getUnpaidTablesMapImgAsPng&showBubbles=0&roomid=2&1627465801615 HTTP/1.1" 200 931671 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "GET /img/gray.png?t=1627465802275 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn&_=1627465795959 HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "GET /php/contenthandler.php?module=queue&command=getJsonProductsOfTableToPay&tableid=21&_=1627465795960 HTTP/1.1" 200 244 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:51 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:52 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:52 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:52 +0200] "POST /php/contenthandler.php?module=queue&command=updateliveorders HTTP/1.1" 200 46 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:53 +0200] "GET /img/gray.png?t=1627465804299 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:54 +0200] "GET /php/contenthandler.php?module=admin&command=isUserAlreadyLoggedIn&_=1627465795961 HTTP/1.1" 200 36 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:54 +0200] "POST /php/contenthandler.php?module=queue&command=declarePaidCreateBillReturnBillId HTTP/1.1" 200 65 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:55 +0200] "GET /img/gray.png?t=1627465806623 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:55 +0200] "GET /php/contenthandler.php?module=admin&command=isPrinterServerActive&_=1627465795962 HTTP/1.1" 200 75 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:55 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"
[28/Jul/2021:11:49:57 +0200] "GET /img/gray.png?t=1627465808277 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:59 +0200] "GET /img/gray.png?t=1627465810277 HTTP/1.1" 200 160 "http://order.fritz.box/paydesk.html?v=2.0.29" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.107 Safari/537.36"
[28/Jul/2021:11:49:59 +0200] "POST /php/contenthandler.php?module=printqueue&command=getNextTicketJobs&fl=16&printersizes=R_30_30_30_30_30_30-F_30_30_30_30-D_30_30_30_30-P_30&v=2.0.0.0&pid=4000&thr=4&instance=1 HTTP/1.1" 200 37 "-" "-"

RAM ist auch noch genug da.

Code: Alles auswählen

$ cat /proc/meminfo
MemTotal:        4030528 kB
MemFree:         2730212 kB
MemAvailable:    3429296 kB
Buffers:          288048 kB
Cached:           601272 kB
...

Keine Ahnung wo hier der Flaschenhals sein sollte.

André

Beitrag von **pichel** » Do 29. Jul 2021, 01:54

Hallo André,

ich kann es dir auch nicht sagen. Ich weiß nur, dass ich seit 2.0.28 keine Anwender mehr habe, die sich über schlechte Performance in dieser Größenordnung beklagen. Vor 2.0.28 konnte es passieren, wenn die Datenbank sehr umfangreich war (insb. die queue-Tabelle sehr viele Einträge hatte) und die Ansichten Küche/Bar/Bereitstellung verwendet wurden.

Kannst du testen, ob es bei Ersatz der HDD durch eine SSD immer noch auftritt?

Gruß,

Stefan

misery · Beitrag von **misery** » Fr 6. Aug 2021, 14:59

Moin Stefan,

ich habe mal ein slow-log (länger 1 Sekunde) beim MariaDB aktiviert.

Code: Alles auswählen

slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 1
log-queries-not-using-indexes

Bisher gab es keine Log-Einträge. Ich denke mal, dass die 5 Sekunden von oben nix mit der Datenbank zu tun haben. Vielleicht braucht das TSE einfach so lange manchmal??

André

Beitrag von **pichel** » So 15. Aug 2021, 11:00

Hallo André,

5 Sekunden bei der TSE kommen mir ein wenig zu lange vor. Natürlich gibt es einen gewissen Overhead durch die Kommunikation mit dem TSEConnector via http und zwischendurch müssen auch mal Aktionen wie Zeitsync, Selbsttest usw. passieren, aber regelmäßige Delays von 5 Sekunden kommen mir trotzdem etwas eigenartig vor und kann ich mir so nicht erklären,

Gruß,

Stefan

misery · Beitrag von **misery** » Do 24. Feb 2022, 10:42

Moin Stefan,

das Eiscafé hat wieder geöffnet.

Die Frage kam auf, ob der Tagesabschluss "immer so langsam" ist. Das dauert wohl 3-4 Minuten jeden Tag. Allerdings sind die Bons bei dem Wetter natürlich nicht so viele. Ist das normal?
Die DB ist seit Oktober 2019 nur etwa 2,4MB als gzip groß.

Das habe ich beim Tagesabschluss im Slow-Log. Chrome gibt auch immer eine Warnmeldung aus, dass es lange dauert. Irgendwann reagiert er natürlich wieder.

Code: Alles auswählen

[23-Feb-2022 18:27:52]  [pool www] pid 1258
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007fcbdf213a80] execute() /var/www/webapp/php/commonutils.php:405
[0x00007fcbdf2139e0] execSql() /var/www/webapp/php/closing.php:474
[0x00007fcbdf213430] createClosingCore() /var/www/webapp/php/closing.php:234
[0x00007fcbdf213330] createClosing() /var/www/webapp/php/closing.php:90
[0x00007fcbdf213190] handleCommand() /var/www/webapp/php/contenthandler.php:86

[23-Feb-2022 18:27:57]  [pool www] pid 1253
script_filename = /var/www/webapp/php/contenthandler.php
[0x00007fcbdf213590] execute() /var/www/webapp/php/commonutils.php:393
[0x00007fcbdf2134f0] fetchSqlAll() /var/www/webapp/php/printqueue.php:804
[0x00007fcbdf2133d0] getNextWorkTicketJobs() /var/www/webapp/php/printqueue.php:876
[0x00007fcbdf213260] getNextTicketJobs() /var/www/webapp/php/printqueue.php:52
[0x00007fcbdf213190] handleCommand() /var/www/webapp/php/contenthandler.php:89

Auch bei einem Update auf eine neue Version dauert relativ lange obwohl bei CPU und IO kaum was passiert. Ist das auch normal?

André

Beitrag von **pichel** » Do 24. Feb 2022, 12:48

Hallo André.

nun ja, ob das "normal" ist, ist wohl eher eine rhetorische Frage...

Nein, so sollte das natürlich nicht sein.

Mich würde interessieren, ob das System insgesamt so lahm ist, oder nur der Tagesabschluss - und das gerne im Zuammenhang mit der Größe der queue-Tabelle, die maßgeblichen Einfluss hat. Dafür würde es mir helfen, wenn du in der Statistikansicht unter Performance mal einen csv-Export erstellst und ihn an diesen Thread anhängst.

Welche Version verwendest du aktuell? Welchen Versionssprung hast du zuletzt gemacht und wie lange hat der in etwa gedauert? Ich frage, um zu sehen, welche DB-Operationen daran beteiligt waren (siehe php/utilities/version.php).

Wenn nur Tagesabschluss so langsam ist. könnten wir per eingestreuten error_log Anweisungen innerhalb der Methode createClosingCore (in php/closing.php) mal prüfen, welcher Bereich oder welche SQL-Anweisung alles ausbremst.

Liegen die DB-Daten auf einer SSD oder HDD?

Gruß,

Stefan

misery · Beitrag von **misery** » Do 24. Feb 2022, 13:50

Moin Stefan,

naja, kann ja sein, dass der Tagesabschluss einfach länger braucht. Betreibe nicht so viele Kassen.

Anbei die CSV-Datei. Derzeit ist die 2.3.3 im Einsatz. Davor war die 2.3.2 drauf. Aber da hatte es noch keine Operationen gegeben, da das Café noch geschlossen war. Spiele neue Version recht "schnell" ein. Sind dann höchstens etwa 3-4 Wochen alt.

Von 2.3.2 auf 2.3.3 hat es etwas mehr als eine Minute gedauert, wie es laut Log aussieht.

Code: Alles auswählen

127.0.0.1 - - [13/Feb/2022:18:16:22 +0100] "GET /install/installer.php?command=checkPhpStatus HTTP/1.1" 200 123 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:16:22 +0100] "GET /install/installer.php?command=getConfig HTTP/1.1" 200 142 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:16:22 +0100] "GET /install/installer.php?command=checkWriteAccess HTTP/1.1" 200 88 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:16:25 +0100] "POST /install/installer.php?command=testDbConnection HTTP/1.1" 200 75 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:16:27 +0100] "POST /install/installer.php?command=gettimezones HTTP/1.1" 200 2996 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:17:44 +0100] "POST /install/installer.php?command=update HTTP/1.1" 200 119 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:17:47 +0100] "GET /logout.php?nocache=1644772666361 HTTP/1.1" 302 5 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"
127.0.0.1 - - [13/Feb/2022:18:17:47 +0100] "GET /index.html HTTP/1.1" 200 4632 "http://localhost:8888/install.html?v=2.3.3&d=1644772574100" "Mozilla/5.0 (X11; Linux x86_64; rv:97.0) Gecko/20100101 Firefox/97.0"

Bei normalen Arbeiten fühlt sich das System nicht langsam an. Nur der erste Zugriff z.B. wenn man als Admin in die Konfiguration geht.

Die Kasse läuft als VM auf einer Synology DS220+. Da läuft sonst NICHTS anderes als das Monitoring des Kassensystems. Ich sehe im Monitoring auch keinerlei Lastspitzen - weder bei der CPU noch beim IO der Platte. Das System langweilt sich zu tode.
Die Festplatte ist eine NAS-Festplatte: Seagate Ironwolf 1TB. Auch dort ist das System kein Stück ausgereizt.

In der CSV-Datei ist für gestern bloß eine Signierung durch TSE gelistet? Da habe ich aber im anderen Log einige mehr.

OrderSprinter-Forum

PHP Warnings im Log

PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log

Re: PHP Warnings im Log