CPU load is very high and growing. Seeing same error over and over in logs

[downingtownryan]

I am very new to Free NAS and i am wondering if there is already a thread for this. I searched the errors i am getting but did not find anything.
I just upgraded to 9.2.1.1 on Friday morning and then noticed yesterday (monday) that the CPU load was slowly climbing. I was at 8 yesterday and now is at about 12. Usually at about 2 for us. Below is the error that i see constantly in the logs.

Feb 25 13:27:36 datastor smbd[19404]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:27:44 datastor smbd[19404]: [2014/02/25 13:27:44.122074, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:27:44 datastor smbd[19404]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:27:51 datastor smbd[19404]: [2014/02/25 13:27:51.073222, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:27:51 datastor smbd[19404]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:27:57 datastor smbd[19404]: [2014/02/25 13:27:57.862003, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:27:57 datastor smbd[19404]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:28:10 datastor smbd[19404]: [2014/02/25 13:28:10.963604, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:28:10 datastor smbd[19404]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:28:11 datastor smbd[33305]: [2014/02/25 13:28:11.715058, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:28:11 datastor smbd[33305]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:28:12 datastor smbd[33305]: [2014/02/25 13:28:12.000735, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:28:12 datastor smbd[33305]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:28:12 datastor smbd[33305]: [2014/02/25 13:28:12.126250, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:28:12 datastor smbd[33305]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:28:12 datastor smbd[33305]: [2014/02/25 13:28:12.152840, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:28:12 datastor smbd[33305]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:28:15 datastor smbd[33305]: [2014/02/25 13:28:15.736332, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:28:15 datastor smbd[33305]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:29:35 datastor smbd[31363]: [2014/02/25 13:29:35.892695, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:29:35 datastor smbd[31363]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:29:35 datastor smbd[31363]: [2014/02/25 13:29:35.910201, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:29:35 datastor smbd[31363]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:03 datastor smbd[35200]: [2014/02/25 13:30:03.107610, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:03 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:03 datastor smbd[35200]: [2014/02/25 13:30:03.301536, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:03 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:03 datastor smbd[35200]: [2014/02/25 13:30:03.524110, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:03 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:05 datastor smbd[35200]: [2014/02/25 13:30:05.679369, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:05 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:05 datastor smbd[35200]: [2014/02/25 13:30:05.860858, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:05 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:07 datastor smbd[35200]: [2014/02/25 13:30:07.055326, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:07 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:07 datastor smbd[35200]: [2014/02/25 13:30:07.362508, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:07 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:08 datastor smbd[35200]: [2014/02/25 13:30:08.048784, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:08 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:09 datastor smbd[35200]: [2014/02/25 13:30:09.470422, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:09 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:09 datastor smbd[35200]: [2014/02/25 13:30:09.645334, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:09 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:09 datastor smbd[35200]: [2014/02/25 13:30:09.802922, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:09 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:30:09 datastor smbd[35200]: [2014/02/25 13:30:09.964881, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:30:09 datastor smbd[35200]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:31:06 datastor smbd[21532]: [2014/02/25 13:31:06.613145, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:31:06 datastor smbd[21532]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.
Feb 25 13:31:25 datastor smbd[35347]: [2014/02/25 13:31:25.425973, 0] ../lib/util/talloc_stack.c:104(talloc_pop)
Feb 25 13:31:25 datastor smbd[35347]: Freed frame ../source3/smbd/open.c:3510, expected ../source3/modules/nfs4_acls.c:936.


It just continues to happen every few seconds.

 

[downingtownryan]

Just as i posted the above question, i saw the below in the log window. Not sure it helps at all.

eb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.635335, 0] ../lib/util/fault.c:72(fault_report)
Feb 25 13:32:34 datastor smbd[21963]: ===============================================================
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.635655, 0] ../lib/util/fault.c:73(fault_report)
Feb 25 13:32:34 datastor smbd[21963]: INTERNAL ERROR: Signal 11 in pid 21963 (4.1.4)
Feb 25 13:32:34 datastor smbd[21963]: Please read the Trouble-Shooting section of the Samba HOWTO
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.635748, 0] ../lib/util/fault.c:75(fault_report)
Feb 25 13:32:34 datastor smbd[21963]: ===============================================================
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.635817, 0] ../source3/lib/util.c:785(smb_panic_s3)
Feb 25 13:32:34 datastor smbd[21963]: PANIC (pid 21963): internal error
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.636378, 0] ../source3/lib/util.c:896(log_stack_trace)
Feb 25 13:32:34 datastor smbd[21963]: BACKTRACE: 5 stack frames:
Feb 25 13:32:34 datastor smbd[21963]: #0 0x801e4c0ab at /usr/local/lib/libsmbconf.so.0
Feb 25 13:32:34 datastor smbd[21963]: #1 0x800846e07 at /usr/local/lib/libsamba-util.so.0
Feb 25 13:32:34 datastor smbd[21963]: #2 0x800846b23 at /usr/local/lib/libsamba-util.so.0
Feb 25 13:32:34 datastor smbd[21963]: #3 0x800846b38 at /usr/local/lib/libsamba-util.so.0
Feb 25 13:32:34 datastor smbd[21963]: #4 0x80369a1a6 at /lib/libthr.so.3
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.636608, 0] ../source3/lib/util.c:797(smb_panic_s3)
Feb 25 13:32:34 datastor smbd[21963]: smb_panic(): calling panic action [/usr/local/libexec/samba/samba-backtrace]
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.709608, 0] ../source3/lib/util.c:805(smb_panic_s3)
Feb 25 13:32:34 datastor smbd[21963]: smb_panic(): action returned status 0
Feb 25 13:32:34 datastor smbd[21963]: [2014/02/25 13:32:34.710217, 0] ../source3/lib/dumpcore.c:317(dump_core)
Feb 25 13:32:34 datastor smbd[21963]: dumping core in /mnt/tank/.system/cores
Feb 25 13:32:34 datastor smbd[21963]:
Feb 25 13:32:34 datastor kernel: pid 21963 (smbd), uid 0: exited on signal 6 (core dumped)

 

[Milkwerm]

I'm getting exactly the same thing, although without high CPU loads at this stage.
2003/2008R2 mixed domain AD connected NAS box.

bd[14065]: ===============================================================
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.557613, 0] ../lib/util/fault.c:73(fault_report)
Feb 27 07:47:51 NAS01 smbd[14065]: INTERNAL ERROR: Signal 11 in pid 14065 (4.1.4)
Feb 27 07:47:51 NAS01 smbd[14065]: Please read the Trouble-Shooting section of the Samba HOWTO
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.557747, 0] ../lib/util/fault.c:75(fault_report)
Feb 27 07:47:51 NAS01 smbd[14065]: ===============================================================
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.557840, 0] ../source3/lib/util.c:785(smb_panic_s3)
Feb 27 07:47:51 NAS01 smbd[14065]: PANIC (pid 14065): internal error
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.558404, 0] ../source3/lib/util.c:896(log_stack_trace)
Feb 27 07:47:51 NAS01 smbd[14065]: BACKTRACE: 5 stack frames:
Feb 27 07:47:51 NAS01 smbd[14065]: #0 0x801e4c0ab at /usr/local/lib/libsmbconf.so.0
Feb 27 07:47:51 NAS01 smbd[14065]: #1 0x800846e07 at /usr/local/lib/libsamba-util.so.0
Feb 27 07:47:51 NAS01 smbd[14065]: #2 0x800846b23 at /usr/local/lib/libsamba-util.so.0
Feb 27 07:47:51 NAS01 smbd[14065]: #3 0x800846b38 at /usr/local/lib/libsamba-util.so.0
Feb 27 07:47:51 NAS01 smbd[14065]: #4 0x80369a1a6 at /lib/libthr.so.3
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.558748, 0] ../source3/lib/util.c:797(smb_panic_s3)
Feb 27 07:47:51 NAS01 smbd[14065]: smb_panic(): calling panic action [/usr/local/libexec/samba/samba-backtrace]
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.648704, 0] ../source3/lib/util.c:805(smb_panic_s3)
Feb 27 07:47:51 NAS01 smbd[14065]: smb_panic(): action returned status 2
Feb 27 07:47:51 NAS01 smbd[14065]: [2014/02/27 07:47:51.649321, 0] ../source3/lib/dumpcore.c:317(dump_core)
Feb 27 07:47:51 NAS01 smbd[14065]: dumping core in /mnt/Tank/.system/cores