pai icon indicating copy to clipboard operation
pai copied to clipboard

Published 20 hours ago • verified publisher icon microsoft

Suspected hang for framework watcher

Open Binyang2014 opened this issue 3 years ago • 0 comments

Reported by customer. Submitted job always in waiting status.

Check framework status. The status for framework is completed So the reason for this issue is framework watcher not sync the status into DB.

framework watcher logs:

2021-10-24T01:26:18.857Z [INFO] Event type=ADDED receivedTs=1635038778857 framework=44977c808113ce9686abc52516207f3f state=Unknown received.
2021-10-24T01:26:18.867Z [INFO] Event type=MODIFED receivedTs=1635038778866 framework=44977c808113ce9686abc52516207f3f state=AttemptCreationPending received.
2021-10-24T01:26:18.868Z [INFO] Sync to write merger type=ADDED receivedTs=1635038778857 framework=44977c808113ce9686abc52516207f3f state=Unknown succeeded.
2021-10-24T01:26:18.878Z [INFO] Sync to write merger type=MODIFED receivedTs=1635038778866 framework=44977c808113ce9686abc52516207f3f state=AttemptCreationPending succeeded.
2021-10-24T01:26:18.895Z [INFO] Event type=MODIFED receivedTs=1635038778895 framework=44977c808113ce9686abc52516207f3f state=AttemptCreationPending received.
2021-10-24T01:26:18.906Z [INFO] Sync to write merger type=MODIFED receivedTs=1635038778895 framework=44977c808113ce9686abc52516207f3f state=AttemptCreationPending succeeded.
2021-10-24T01:26:18.929Z [INFO] Event type=MODIFED receivedTs=1635038778928 framework=44977c808113ce9686abc52516207f3f state=AttemptCreationRequested received.
2021-10-24T01:26:18.938Z [INFO] Sync to write merger type=MODIFED receivedTs=1635038778928 framework=44977c808113ce9686abc52516207f3f state=AttemptCreationRequested succeeded.
2021-10-24T01:26:18.967Z [INFO] Event type=MODIFED receivedTs=1635038778967 framework=44977c808113ce9686abc52516207f3f state=AttemptPreparing received.
2021-10-24T01:26:18.974Z [INFO] Sync to write merger type=MODIFED receivedTs=1635038778967 framework=44977c808113ce9686abc52516207f3f state=AttemptPreparing succeeded.
2021-10-24T01:26:18.975Z [INFO] Event type=MODIFED receivedTs=1635038778975 framework=44977c808113ce9686abc52516207f3f state=AttemptPreparing received.
2021-10-24T01:26:18.987Z [INFO] Sync to write merger type=MODIFED receivedTs=1635038778975 framework=44977c808113ce9686abc52516207f3f state=AttemptPreparing succeeded.
2021-10-24T02:36:24.250Z [INFO] Frameworks are listed.
2021-10-24T02:36:24.284Z [INFO] Event type=MODIFED receivedTs=1635042984284 framework=00d343750dfbf618731d888332e5ba7e state=AttemptRunning received.
2021-10-24T02:36:24.285Z [INFO] Event type=MODIFED receivedTs=1635042984285 framework=0865f860bc09dbff0504b2913ff4bcae state=AttemptRunning received.
2021-10-24T02:36:24.286Z [INFO] Event type=MODIFED receivedTs=1635042984286 framework=0cca4c33382c47e7a16c34ed943c9551 state=AttemptPreparing received.
2021-10-24T02:36:24.287Z [INFO] Event type=MODIFED receivedTs=1635042984287 framework=30d4a70e14a17e3eb6a0161b6b749b87 state=AttemptRunning received.
2021-10-24T02:36:24.289Z [INFO] Event type=MODIFED receivedTs=1635042984289 framework=44977c808113ce9686abc52516207f3f state=AttemptPreparing received.
2021-10-24T02:36:24.290Z [INFO] Event type=MODIFED receivedTs=1635042984290 framework=454b34460fde67838115f39d03d6c2b9 state=AttemptRunning received.
2021-10-24T02:36:24.290Z [INFO] Event type=MODIFED receivedTs=1635042984290 framework=54be7a5968114a2e73126f01da6d7699 state=AttemptRunning received.
2021-10-24T02:36:24.291Z [INFO] Event type=MODIFED receivedTs=1635042984291 framework=60ae7dd546bbc479f63e37304e7361a9 state=AttemptRunning received.
2021-10-24T02:36:24.292Z [INFO] Event type=MODIFED receivedTs=1635042984292 framework=6f260ac585da22fa0c3d337f9d051e78 state=AttemptRunning received.
2021-10-24T02:36:24.293Z [INFO] Event type=MODIFED receivedTs=1635042984292 framework=73aa88190f3daf4500d48788217c1c69 state=AttemptRunning received.
2021-10-24T02:36:24.293Z [INFO] Event type=MODIFED receivedTs=1635042984293 framework=814f2558d062da33168beeb729dcc9b2 state=AttemptPreparing received.
2021-10-24T02:36:24.294Z [INFO] Event type=MODIFED receivedTs=1635042984294 framework=a1299990b0f6edb4786578ae3c48c575 state=AttemptRunning received.
2021-10-24T02:36:24.294Z [INFO] Event type=MODIFED receivedTs=1635042984294 framework=ac8a5b2c11886d3459d435faf1a3ae8b state=AttemptRunning received.
2021-10-24T02:36:24.295Z [INFO] Event type=MODIFED receivedTs=1635042984295 framework=b3ec91761823f7c679c27d7d1663de0d state=AttemptRunning received.
2021-10-24T02:36:24.295Z [INFO] Event type=MODIFED receivedTs=1635042984295 framework=e37c04101c357bb7a94e6d916fa7c3ed state=AttemptRunning received.
2021-10-24T02:36:24.388Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984286 framework=0cca4c33382c47e7a16c34ed943c9551 state=AttemptPreparing succeeded.
2021-10-24T02:36:24.388Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984284 framework=00d343750dfbf618731d888332e5ba7e state=AttemptRunning succeeded.
2021-10-24T02:36:24.389Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984285 framework=0865f860bc09dbff0504b2913ff4bcae state=AttemptRunning succeeded.
2021-10-24T02:36:24.391Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984287 framework=30d4a70e14a17e3eb6a0161b6b749b87 state=AttemptRunning succeeded.
2021-10-24T02:36:24.393Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984289 framework=44977c808113ce9686abc52516207f3f state=AttemptPreparing succeeded.
2021-10-24T02:36:24.393Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984292 framework=6f260ac585da22fa0c3d337f9d051e78 state=AttemptRunning succeeded.
2021-10-24T02:36:24.394Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984290 framework=54be7a5968114a2e73126f01da6d7699 state=AttemptRunning succeeded.
2021-10-24T02:36:24.394Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984291 framework=60ae7dd546bbc479f63e37304e7361a9 state=AttemptRunning succeeded.
2021-10-24T02:36:24.395Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984290 framework=454b34460fde67838115f39d03d6c2b9 state=AttemptRunning succeeded.
2021-10-24T02:36:24.395Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984292 framework=73aa88190f3daf4500d48788217c1c69 state=AttemptRunning succeeded.
2021-10-24T02:36:24.396Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984293 framework=814f2558d062da33168beeb729dcc9b2 state=AttemptPreparing succeeded.
2021-10-24T02:36:24.396Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984294 framework=a1299990b0f6edb4786578ae3c48c575 state=AttemptRunning succeeded.
2021-10-24T02:36:24.397Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984295 framework=e37c04101c357bb7a94e6d916fa7c3ed state=AttemptRunning succeeded.
2021-10-24T02:36:24.397Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984295 framework=b3ec91761823f7c679c27d7d1663de0d state=AttemptRunning succeeded.
2021-10-24T02:36:24.398Z [INFO] Sync to write merger type=MODIFED receivedTs=1635042984294 framework=ac8a5b2c11886d3459d435faf1a3ae8b state=AttemptRunning succeeded.

The log not updated for about 30 mins. After restart the db-controller, job status back to normal and log is:

2021-10-25T03:39:23.249Z [INFO] Frameworks are listed.
2021-10-25T03:39:23.328Z [INFO] Event type=ADDED receivedTs=1635133163328 framework=00d343750dfbf618731d888332e5ba7e state=AttemptRunning received.
2021-10-25T03:39:23.334Z [INFO] Event type=ADDED receivedTs=1635133163334 framework=0865f860bc09dbff0504b2913ff4bcae state=AttemptRunning received.
2021-10-25T03:39:23.335Z [INFO] Event type=ADDED receivedTs=1635133163335 framework=0cca4c33382c47e7a16c34ed943c9551 state=AttemptPreparing received.
2021-10-25T03:39:23.336Z [INFO] Event type=ADDED receivedTs=1635133163335 framework=15d8a517762cba1d8628b2780abef45a state=Completed received.
2021-10-25T03:39:23.336Z [INFO] Event type=ADDED receivedTs=1635133163336 framework=25720179d27ace5c8f02cad1f93453db state=Completed received.
2021-10-25T03:39:23.337Z [INFO] Event type=ADDED receivedTs=1635133163336 framework=28817a023384c861ea76fe0a475838c0 state=Completed received.
2021-10-25T03:39:23.337Z [INFO] Event type=ADDED receivedTs=1635133163337 framework=30d4a70e14a17e3eb6a0161b6b749b87 state=AttemptRunning received.
2021-10-25T03:39:23.337Z [INFO] Event type=ADDED receivedTs=1635133163337 framework=44977c808113ce9686abc52516207f3f state=AttemptRunning received.
2021-10-25T03:39:23.338Z [INFO] Event type=ADDED receivedTs=1635133163338 framework=454b34460fde67838115f39d03d6c2b9 state=AttemptRunning received.
2021-10-25T03:39:23.338Z [INFO] Event type=ADDED receivedTs=1635133163338 framework=52ea63f17cb952a839ba37b48e569501 state=AttemptPreparing received.
2021-10-25T03:39:23.339Z [INFO] Event type=ADDED receivedTs=1635133163339 framework=54be7a5968114a2e73126f01da6d7699 state=Completed received.
2021-10-25T03:39:23.339Z [INFO] Event type=ADDED receivedTs=1635133163339 framework=60ae7dd546bbc479f63e37304e7361a9 state=Completed received.
2021-10-25T03:39:23.340Z [INFO] Event type=ADDED receivedTs=1635133163340 framework=6f260ac585da22fa0c3d337f9d051e78 state=AttemptRunning received.
2021-10-25T03:39:23.340Z [INFO] Event type=ADDED receivedTs=1635133163340 framework=73aa88190f3daf4500d48788217c1c69 state=AttemptRunning received.
2021-10-25T03:39:23.341Z [INFO] Event type=ADDED receivedTs=1635133163341 framework=814f2558d062da33168beeb729dcc9b2 state=AttemptPreparing received.
2021-10-25T03:39:23.341Z [INFO] Event type=ADDED receivedTs=1635133163341 framework=a1299990b0f6edb4786578ae3c48c575 state=AttemptRunning received.
2021-10-25T03:39:23.342Z [INFO] Event type=ADDED receivedTs=1635133163341 framework=ac8a5b2c11886d3459d435faf1a3ae8b state=AttemptRunning received.
2021-10-25T03:39:23.342Z [INFO] Event type=ADDED receivedTs=1635133163342 framework=b3ec91761823f7c679c27d7d1663de0d state=AttemptRunning received.
2021-10-25T03:39:23.342Z [INFO] Event type=ADDED receivedTs=1635133163342 framework=cac69d75b00e28b11e13e23f5712d272 state=AttemptPreparing received.
2021-10-25T03:39:23.343Z [INFO] Event type=ADDED receivedTs=1635133163343 framework=e34a2a5cdf7fea0d46657c824e745245 state=AttemptRunning received.
2021-10-25T03:39:23.343Z [INFO] Event type=ADDED receivedTs=1635133163343 framework=e37c04101c357bb7a94e6d916fa7c3ed state=AttemptRunning received.
2021-10-25T03:39:23.344Z [INFO] Event type=ADDED receivedTs=1635133163344 framework=ecaaea92719db801231340b88320d70d state=Completed received.
2021-10-25T03:39:23.548Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163328 framework=00d343750dfbf618731d888332e5ba7e state=AttemptRunning succeeded.
2021-10-25T03:39:23.550Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163335 framework=0cca4c33382c47e7a16c34ed943c9551 state=AttemptPreparing succeeded.
2021-10-25T03:39:23.551Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163334 framework=0865f860bc09dbff0504b2913ff4bcae state=AttemptRunning succeeded.
2021-10-25T03:39:23.552Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163336 framework=28817a023384c861ea76fe0a475838c0 state=Completed succeeded.
2021-10-25T03:39:23.553Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163335 framework=15d8a517762cba1d8628b2780abef45a state=Completed succeeded.
2021-10-25T03:39:23.553Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163336 framework=25720179d27ace5c8f02cad1f93453db state=Completed succeeded.
2021-10-25T03:39:23.554Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163337 framework=30d4a70e14a17e3eb6a0161b6b749b87 state=AttemptRunning succeeded.
2021-10-25T03:39:23.555Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163337 framework=44977c808113ce9686abc52516207f3f state=AttemptRunning succeeded.
2021-10-25T03:39:23.555Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163338 framework=454b34460fde67838115f39d03d6c2b9 state=AttemptRunning succeeded.
2021-10-25T03:39:23.555Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163339 framework=60ae7dd546bbc479f63e37304e7361a9 state=Completed succeeded.
2021-10-25T03:39:23.556Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163339 framework=54be7a5968114a2e73126f01da6d7699 state=Completed succeeded.
2021-10-25T03:39:23.556Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163340 framework=6f260ac585da22fa0c3d337f9d051e78 state=AttemptRunning succeeded.
2021-10-25T03:39:23.557Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163342 framework=b3ec91761823f7c679c27d7d1663de0d state=AttemptRunning succeeded.
2021-10-25T03:39:23.557Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163340 framework=73aa88190f3daf4500d48788217c1c69 state=AttemptRunning succeeded.
2021-10-25T03:39:23.557Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163341 framework=814f2558d062da33168beeb729dcc9b2 state=AttemptPreparing succeeded.
2021-10-25T03:39:23.558Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163342 framework=cac69d75b00e28b11e13e23f5712d272 state=AttemptPreparing succeeded.
2021-10-25T03:39:23.558Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163338 framework=52ea63f17cb952a839ba37b48e569501 state=AttemptPreparing succeeded.
2021-10-25T03:39:23.558Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163341 framework=a1299990b0f6edb4786578ae3c48c575 state=AttemptRunning succeeded.
2021-10-25T03:39:23.560Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163341 framework=ac8a5b2c11886d3459d435faf1a3ae8b state=AttemptRunning succeeded.
2021-10-25T03:39:23.560Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163344 framework=ecaaea92719db801231340b88320d70d state=Completed succeeded.
2021-10-25T03:39:23.560Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163343 framework=e34a2a5cdf7fea0d46657c824e745245 state=AttemptRunning succeeded.
2021-10-25T03:39:23.561Z [INFO] Sync to write merger type=ADDED receivedTs=1635133163343 framework=e37c04101c357bb7a94e6d916fa7c3ed state=AttemptRunning succeeded.

Please notice the framework 28817a023384c861ea76fe0a475838c0 no appear in first log file but already completed in second log file

Binyang2014 avatar Oct 25 '21 05:10 Binyang2014