Migration 6.3.7 Issue (SQL and PHP error) after successful migration.

Hi all,

After Projeqtor instance upgrad from 6.1.2 to 6.3.7, it works well during 1 afternoon.

during this afternoon : i used the organisation's function to put my projects in the corresponding service an department, using hierarchy ability..

after that, i experienced Issue. it starts with :

2017-10-24 11:25:47.005 ***** ERROR ***** [V6.3.7] ERROR *****
2017-10-24 11:25:47.006 ***** ERROR ***** [V6.3.7] on file '/xxx/www/projeqtor/tool/dynamicListDependency.php' at line (83)
2017-10-24 11:25:47.006 ***** ERROR ***** [V6.3.7] cause = Undefined offset: 2184

and continue with : (i t ried to update reference data in administration interface)

2017-10-24 11:33:54.433 ===== TRACE ===== Logfile->purge() : Technical trace to keep current log file
2017-10-24 11:34:07.507 ===== TRACE ===== => setting unlimited execution time for script (more than 100 Action to update)
2017-10-24 11:34:07.507 ===== TRACE ===== => 299 Action to update
2017-10-24 11:34:10.843 ===== TRACE ===== => 100 Action done...
2017-10-24 11:34:13.064 ===== TRACE ===== => 200 Action done...
2017-10-24 11:34:30.797 ===== TRACE ===== => setting unlimited execution time for script (more than 100 Activity to update)
2017-10-24 11:34:30.797 ===== TRACE ===== => 1759 Activity to update
2017-10-24 11:34:36.412 ===== TRACE ===== DISCONNECTED USER 'u0557556'
2017-10-24 11:34:42.787 ===== TRACE ===== NEW CONNECTED USER 'u0557556'
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] Exception-[HY000] SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] For query : update planningelement set assignedWork='1196.916' , leftWork='174.96' , plannedWork='1709.81' , progress='90' , marginWork='2367.48' , marginWorkPct='58' where id=35
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] Strack trace :
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #0 Sql->query called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:1397]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #1 SqlElement->updateSqlElement called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:915]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #2 SqlElement->saveSqlElement called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:611]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #3 SqlElement->save called at [/xxx/www/projeqtor/model/PlanningElement.php:397]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #4 PlanningElement->save called at [/xxx/www/projeqtor/model/ProjectPlanningElementMain.php:176]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #5 ProjectPlanningElementMain->save called at [/xxx/www/projeqtor/model/ProjectPlanningElementMain.php:279]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #6 ProjectPlanningElementMain->updateSynthesisProject called at [/xxx/www/projeqtor/model/PlanningElement.php:756]
2017-10-24 11:36:26.930 ***** ERROR ***** [V6.3.7] #7 PlanningElement->updateSynthesis called at [/xxx/www/projeqtor/model/PlanningElement.php:435]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #8 PlanningElement->save called at [/xxx/www/projeqtor/model/ProjectPlanningElementMain.php:176]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #9 ProjectPlanningElementMain->save called at [/xxx/www/projeqtor/model/ProjectPlanningElementMain.php:279]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #10 ProjectPlanningElementMain->updateSynthesisProject called at [/xxx/www/projeqtor/model/PlanningElement.php:756]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #11 PlanningElement->updateSynthesis called at [/xxx/www/projeqtor/model/PlanningElement.php:435]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #12 PlanningElement->save called at [/xxx/www/projeqtor/model/ActivityPlanningElementMain.php:194]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #13 ActivityPlanningElementMain->save called at [/xxx/www/projeqtor/model/PlanningElement.php:732]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #14 PlanningElement->updateSynthesisObj called at [/xxx/www/projeqtor/model/PlanningElement.php:758]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #15 PlanningElement->updateSynthesis called at [/xxx/www/projeqtor/model/Assignment.php:203]
2017-10-24 11:36:26.931 ***** ERROR ***** [V6.3.7] #16 Assignment->save called at [/xxx/www/projeqtor/tool/saveAssignment.php:165]

and now, my instance is very very slow and i expériences other problems like this :

2017-10-24 11:56:35.533 ***** ERROR ***** [V6.3.7] Exception-[HY000] SQLSTATE[HY000]: General error: 1205 Lock wait timeout exceeded; try restarting transaction
2017-10-24 11:56:35.533 ***** ERROR ***** [V6.3.7] For query : update kpivalue set kpiValue='0.42011711711712' where id=197
2017-10-24 11:56:35.533 ***** ERROR ***** [V6.3.7] Strack trace :
2017-10-24 11:56:35.533 ***** ERROR ***** [V6.3.7] #0 Sql->query called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:1397]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #1 SqlElement->updateSqlElement called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:915]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #2 SqlElement->saveSqlElement called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:611]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #3 SqlElement->save called at [/xxx/www/projeqtor/model/KpiValue.php:74]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #4 KpiValue->save called at [/xxx/www/projeqtor/model/KpiValue.php:231]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #5 KpiValue->consolidate called at [/xxx/www/projeqtor/model/KpiValue.php:135]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #6 KpiValue->calculateKpi called at [/xxx/www/projeqtor/model/ProjectPlanningElementMain.php:204]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #7 ProjectPlanningElementMain->save called at [/xxx/www/projeqtor/model/ProjectPlanningElementMain.php:279]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #8 ProjectPlanningElementMain->updateSynthesisProject called at [/xxx/www/projeqtor/model/PlanningElement.php:756]
2017-10-24 11:56:35.534 ***** ERROR ***** [V6.3.7] #9 PlanningElement->updateSynthesis called at [/xxx/www/projeqtor/model/PlanningElement.php:435]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #10 PlanningElement->save called at [/xxx/www/projeqtor/model/ActivityPlanningElementMain.php:194]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #11 ActivityPlanningElementMain->save called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:1518]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #12 SqlElement->saveDependantObjects called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:1456]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #13 SqlElement->updateSqlElement called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:915]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #14 SqlElement->saveSqlElement called at [/xxx/www/projeqtor/model/persistence/SqlElement.php:611]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #15 SqlElement->save called at [/xxx/www/projeqtor/model/ActivityMain.php:319]
2017-10-24 11:56:35.535 ***** ERROR ***** [V6.3.7] #16 ActivityMain->save called at [/xxx/www/projeqtor/tool/saveObject.php:78]

and :

2017-10-24 13:42:31.319 ***** ERROR ***** [V6.3.7] ERROR *****
2017-10-24 13:42:31.319 ***** ERROR ***** [V6.3.7] on file '/xxx/www/projeqtor/model/persistence/SqlElement.php' at line (2635)
2017-10-24 13:42:31.320 ***** ERROR ***** [V6.3.7] cause = array_key_exists() expects parameter 2 to be array, boolean given

It's the first time i Have a such problem, but it's very important for us.

Thank's a lot for your quick answer.

Best regards.

In addition, now, when i try to "update reference" on activity, the process start indicated need to update 1759.

the 700 first has been done normaly :

2017-10-24 17:17:28.446 ===== TRACE ===== NEW CONNECTED USER 'admin'
2017-10-24 17:17:40.730 ===== TRACE ===== => setting unlimited execution time for script (more than 100 Action to update)
2017-10-24 17:17:40.730 ===== TRACE ===== => 299 Action to update
2017-10-24 17:17:43.686 ===== TRACE ===== => 100 Action done...
2017-10-24 17:17:47.178 ===== TRACE ===== => 200 Action done...
2017-10-24 17:18:06.602 ===== TRACE ===== => setting unlimited execution time for script (more than 100 Activity to update)
2017-10-24 17:18:06.602 ===== TRACE ===== => 1759 Activity to update
2017-10-24 17:18:16.877 ===== TRACE ===== => 100 Activity done...
2017-10-24 17:18:27.165 ===== TRACE ===== => 200 Activity done...
2017-10-24 17:18:37.810 ===== TRACE ===== => 300 Activity done...
2017-10-24 17:18:59.879 ===== TRACE ===== => 400 Activity done...
2017-10-24 17:19:15.865 ===== TRACE ===== => 500 Activity done...
2017-10-24 17:19:33.869 ===== TRACE ===== => 600 Activity done...
2017-10-24 17:19:53.622 ===== TRACE ===== => 700 Activity done...

But nothing more, even if i continue to see the hour-glass...

hum hum !!!

The problem is now, activity creation take 20 seconds, before it was done in 1 or 2 seconds....

ouch !!!!