2014-05-27 14:39:53 User.Debug 192.168.4.200 May 27 14:39:53 manage.py: [middleware.notifier:227] Calling: restart(cifs) 2014-05-27 14:39:53 User.Debug 192.168.4.200 May 27 14:39:53 manage.py: [middleware.notifier:185] Executing: /usr/sbin/service ix-samba quietstart 2014-05-27 14:39:54 User.Debug 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:39:54 User.Debug 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [middleware.notifier:220] Popen()ing: /sbin/zfs list -H -o name -t volume,filesystem 2014-05-27 14:39:54 User.Notice 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /sbin/sysctl -n 'kern.maxfilesperproc' 2014-05-27 14:39:54 User.Notice 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint,name 2014-05-27 14:39:54 User.Notice 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint 2014-05-27 14:39:54 User.Notice 192.168.4.200 May 27 14:39:54 last message repeated 2 times 2014-05-27 14:39:54 User.Notice 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/pdbedit -d 0 -i smbpasswd:/tmp/tmpxGluxT -s /usr/local/etc/smb4.conf -e tdbsam:/var/etc/private/passdb.tdb 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.842476, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.842476, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.844569, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.844569, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.846288, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.846288, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.847834, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.847834, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.849737, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.849737, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.851346, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.851346, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.853455, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.853455, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.855347, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.855347, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.857642, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.857642, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.859601, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.859601, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: [2014/05/27 14:39:54.861718, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: [2014/05/27 14:39:54.861718, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:39:55 Daemon.Error 192.168.4.200 May 27 14:39:54 winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 System4.Info 192.168.4.200 May 27 14:39:54 kernel: May 27 14:39:54 freenas winbindd[34162]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:54 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='bhoover' ntgroup='bhoover' 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='New_Tampa' ntgroup='New_Tampa' 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='cmickelson' ntgroup='cmickelson' 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='ftpuser' ntgroup='ftpuser' 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='stierney' ntgroup='stierney' 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='lcampagna' ntgroup='lcampagna' 2014-05-27 14:39:55 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='public' ntgroup='public' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='freenasusers' ntgroup='freenasusers' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:55 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='cschappacher' ntgroup='cschappacher' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:56 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='jpatron' ntgroup='jpatron' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:56 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='btsync' ntgroup='btsync' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:56 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='tfeury' ntgroup='tfeury' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:56 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='test' ntgroup='test' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:56 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='jdevenny' ntgroup='jdevenny' 2014-05-27 14:39:56 User.Notice 192.168.4.200 May 27 14:39:56 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='gmorris' ntgroup='gmorris' 2014-05-27 14:39:57 User.Debug 192.168.4.200 May 27 14:39:56 manage.py: [middleware.notifier:199] Executed: /usr/sbin/service ix-samba quietstart 2014-05-27 14:39:57 User.Debug 192.168.4.200 May 27 14:39:56 manage.py: [middleware.notifier:185] Executing: /usr/sbin/service samba_server forcestop 2014-05-27 14:39:57 Daemon.Notice 192.168.4.200 May 27 14:39:57 notifier: Stopping winbindd. 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34160]: [2014/05/27 14:39:57.137768, 0, pid=34160, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34160]: [2014/05/27 14:39:57.137768, 0, pid=34160, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34160]: Got sig[15] terminate (is_parent=1) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34160]: Got sig[15] terminate (is_parent=1) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34162]: [2014/05/27 14:39:57.142953, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34162]: [2014/05/27 14:39:57.142953, 0, pid=34162, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34162]: Got sig[15] terminate (is_parent=0) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34162]: Got sig[15] terminate (is_parent=0) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34164]: [2014/05/27 14:39:57.144364, 0, pid=34164, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34164]: [2014/05/27 14:39:57.144364, 0, pid=34164, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34164]: Got sig[15] terminate (is_parent=0) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34164]: Got sig[15] terminate (is_parent=0) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34166]: [2014/05/27 14:39:57.149817, 0, pid=34166, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34166]: [2014/05/27 14:39:57.149817, 0, pid=34166, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd.c:234(winbindd_sig_term_handler) 2014-05-27 14:39:57 Daemon.Error 192.168.4.200 May 27 14:39:57 winbindd[34166]: Got sig[15] terminate (is_parent=0) 2014-05-27 14:39:57 System4.Info 192.168.4.200 May 27 14:39:57 kernel: May 27 14:39:57 freenas winbindd[34166]: Got sig[15] terminate (is_parent=0) 2014-05-27 14:39:58 Daemon.Notice 192.168.4.200 May 27 14:39:58 notifier: Waiting for PIDS: 34160, 34160. 2014-05-27 14:39:58 Daemon.Notice 192.168.4.200 May 27 14:39:58 notifier: Stopping smbd. 2014-05-27 14:39:58 Daemon.Notice 192.168.4.200 May 27 14:39:58 notifier: Waiting for PIDS: 34156. 2014-05-27 14:39:58 Daemon.Notice 192.168.4.200 May 27 14:39:58 notifier: Stopping nmbd. 2014-05-27 14:39:58 Daemon.Notice 192.168.4.200 May 27 14:39:58 notifier: Waiting for PIDS: 34152. 2014-05-27 14:39:58 User.Debug 192.168.4.200 May 27 14:39:58 manage.py: [middleware.notifier:199] Executed: /usr/sbin/service samba_server forcestop 2014-05-27 14:39:58 User.Debug 192.168.4.200 May 27 14:39:58 manage.py: [middleware.notifier:185] Executing: /usr/sbin/service samba_server quietrestart 2014-05-27 14:39:58 User.Debug 192.168.4.200 May 27 14:39:58 manage.py: [middleware.notifier:199] Executed: /usr/sbin/service samba_server quietrestart 2014-05-27 14:39:58 User.Debug 192.168.4.200 May 27 14:39:58 manage.py: [middleware.notifier:220] Popen()ing: /bin/pgrep -F /var/run/samba/smbd.pid smbd 2014-05-27 14:39:59 User.Debug 192.168.4.200 May 27 14:39:59 manage.py: [middleware.notifier:227] Calling: restart(cifs) 2014-05-27 14:39:59 User.Debug 192.168.4.200 May 27 14:39:59 manage.py: [middleware.notifier:185] Executing: /usr/sbin/service ix-samba quietstart 2014-05-27 14:40:00 Cron.Info 192.168.4.200 May 27 14:40:00 /usr/sbin/cron[34534]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:40:00 Cron.Info 192.168.4.200 May 27 14:40:00 /usr/sbin/cron[34536]: (root) CMD (/usr/libexec/atrun) 2014-05-27 14:40:00 Cron.Info 192.168.4.200 May 27 14:40:00 /usr/sbin/cron[34535]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/alert.py > /dev/null 2>&1) 2014-05-27 14:40:01 User.Debug 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:40:01 User.Debug 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [middleware.notifier:220] Popen()ing: /sbin/zfs list -H -o name -t volume,filesystem 2014-05-27 14:40:01 User.Notice 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /sbin/sysctl -n 'kern.maxfilesperproc' 2014-05-27 14:40:01 User.Notice 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint,name 2014-05-27 14:40:01 User.Notice 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint 2014-05-27 14:40:01 User.Notice 192.168.4.200 May 27 14:40:01 last message repeated 2 times 2014-05-27 14:40:01 User.Notice 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/pdbedit -d 0 -i smbpasswd:/tmp/tmp18WCIJ -s /usr/local/etc/smb4.conf -e tdbsam:/var/etc/private/passdb.tdb 2014-05-27 14:40:01 User.Notice 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='bhoover' ntgroup='bhoover' 2014-05-27 14:40:02 User.Notice 192.168.4.200 May 27 14:40:01 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='New_Tampa' ntgroup='New_Tampa' 2014-05-27 14:40:02 User.Notice 192.168.4.200 May 27 14:40:02 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='cmickelson' ntgroup='cmickelson' 2014-05-27 14:40:02 User.Notice 192.168.4.200 May 27 14:40:02 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='ftpuser' ntgroup='ftpuser' 2014-05-27 14:40:02 User.Debug 192.168.4.200 May 27 14:40:02 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:40:02 User.Debug 192.168.4.200 May 27 14:40:02 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:40:02 User.Notice 192.168.4.200 May 27 14:40:02 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='stierney' ntgroup='stierney' 2014-05-27 14:40:02 User.Debug 192.168.4.200 May 27 14:40:02 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:40:02 User.Notice 192.168.4.200 May 27 14:40:02 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='lcampagna' ntgroup='lcampagna' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:02 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='public' ntgroup='public' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='freenasusers' ntgroup='freenasusers' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='cschappacher' ntgroup='cschappacher' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='jpatron' ntgroup='jpatron' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='btsync' ntgroup='btsync' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='tfeury' ntgroup='tfeury' 2014-05-27 14:40:03 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='test' ntgroup='test' 2014-05-27 14:40:04 User.Notice 192.168.4.200 May 27 14:40:03 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='jdevenny' ntgroup='jdevenny' 2014-05-27 14:40:04 User.Notice 192.168.4.200 May 27 14:40:04 generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net groupmap add unixgroup='gmorris' ntgroup='gmorris' 2014-05-27 14:40:04 User.Debug 192.168.4.200 May 27 14:40:04 manage.py: [middleware.notifier:199] Executed: /usr/sbin/service ix-samba quietstart 2014-05-27 14:40:04 User.Debug 192.168.4.200 May 27 14:40:04 manage.py: [middleware.notifier:185] Executing: /usr/sbin/service samba_server forcestop 2014-05-27 14:40:04 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: winbindd not running? (check /var/run/samba/winbindd.pid). 2014-05-27 14:40:04 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: smbd not running? (check /var/run/samba/smbd.pid). 2014-05-27 14:40:04 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: nmbd not running? (check /var/run/samba/nmbd.pid). 2014-05-27 14:40:04 User.Debug 192.168.4.200 May 27 14:40:04 manage.py: [middleware.notifier:199] Executed: /usr/sbin/service samba_server forcestop 2014-05-27 14:40:04 User.Debug 192.168.4.200 May 27 14:40:04 manage.py: [middleware.notifier:185] Executing: /usr/sbin/service samba_server quietrestart 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: Performing sanity check on Samba configuration: OK 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: winbindd not running? (check /var/run/samba/winbindd.pid). 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: smbd not running? (check /var/run/samba/smbd.pid). 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:04 notifier: nmbd not running? (check /var/run/samba/nmbd.pid). 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:05 notifier: Performing sanity check on Samba configuration: OK 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:05 notifier: Starting nmbd. 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:05 notifier: Starting smbd. 2014-05-27 14:40:05 Daemon.Notice 192.168.4.200 May 27 14:40:05 notifier: Starting winbindd. 2014-05-27 14:40:05 User.Debug 192.168.4.200 May 27 14:40:05 manage.py: [middleware.notifier:199] Executed: /usr/sbin/service samba_server quietrestart 2014-05-27 14:40:05 User.Debug 192.168.4.200 May 27 14:40:05 manage.py: [middleware.notifier:220] Popen()ing: /bin/pgrep -F /var/run/samba/smbd.pid smbd 2014-05-27 14:40:05 Daemon.Error 192.168.4.200 May 27 14:40:05 winbindd[34671]: [2014/05/27 14:40:05.358901, 0, pid=34671, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:3196(initialize_winbindd_cache) 2014-05-27 14:40:05 System4.Info 192.168.4.200 May 27 14:40:05 kernel: May 27 14:40:05 freenas winbindd[34671]: [2014/05/27 14:40:05.358901, 0, pid=34671, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:3196(initialize_winbindd_cache) 2014-05-27 14:40:05 Daemon.Error 192.168.4.200 May 27 14:40:05 winbindd[34671]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 2014-05-27 14:40:05 System4.Info 192.168.4.200 May 27 14:40:05 kernel: May 27 14:40:05 freenas winbindd[34671]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 2014-05-27 14:40:05 User.Debug 192.168.4.200 May 27 14:40:05 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:40:05 User.Debug 192.168.4.200 May 27 14:40:05 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34534 2014-05-27 14:40:05 User.Debug 192.168.4.200 May 27 14:40:05 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:40:10 Daemon.Error 192.168.4.200 May 27 14:40:10 winbindd[34674]: [2014/05/27 14:40:10.276710, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:40:10 System4.Info 192.168.4.200 May 27 14:40:10 kernel: May 27 14:40:10 freenas winbindd[34674]: [2014/05/27 14:40:10.276710, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:40:10 Daemon.Error 192.168.4.200 May 27 14:40:10 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:40:10 System4.Info 192.168.4.200 May 27 14:40:10 kernel: May 27 14:40:10 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:40:33 Auth.Info 192.168.4.200 May 27 14:40:33 sshd[34689]: Accepted password for root from 192.168.4.118 port 27310 ssh2 2014-05-27 14:41:00 Cron.Info 192.168.4.200 May 27 14:41:00 /usr/sbin/cron[34702]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:41:01 User.Debug 192.168.4.200 May 27 14:41:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:41:04 User.Debug 192.168.4.200 May 27 14:41:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:41:04 User.Debug 192.168.4.200 May 27 14:41:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34702 2014-05-27 14:41:04 User.Debug 192.168.4.200 May 27 14:41:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:41:41 Daemon.Error 192.168.4.200 May 27 14:41:41 winbindd[34674]: [2014/05/27 14:41:41.790333, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:41:41 System4.Info 192.168.4.200 May 27 14:41:41 kernel: May 27 14:41:41 freenas winbindd[34674]: [2014/05/27 14:41:41.790333, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:41:41 Daemon.Error 192.168.4.200 May 27 14:41:41 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:41:41 System4.Info 192.168.4.200 May 27 14:41:41 kernel: May 27 14:41:41 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: [2014/05/27 14:41:42.018637, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: [2014/05/27 14:41:42.018637, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: [2014/05/27 14:41:42.057095, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: [2014/05/27 14:41:42.057095, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: [2014/05/27 14:41:42.057658, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: [2014/05/27 14:41:42.057658, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: [2014/05/27 14:41:42.058193, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: [2014/05/27 14:41:42.058193, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: [2014/05/27 14:41:42.058729, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: [2014/05/27 14:41:42.058729, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:41:42 Daemon.Error 192.168.4.200 May 27 14:41:42 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1009 2014-05-27 14:41:42 System4.Info 192.168.4.200 May 27 14:41:42 kernel: May 27 14:41:42 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1009 2014-05-27 14:42:00 Cron.Info 192.168.4.200 May 27 14:42:00 /usr/sbin/cron[34739]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:42:01 User.Debug 192.168.4.200 May 27 14:42:00 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:42:03 User.Debug 192.168.4.200 May 27 14:42:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:42:03 User.Debug 192.168.4.200 May 27 14:42:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34739 2014-05-27 14:42:03 User.Debug 192.168.4.200 May 27 14:42:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:43:00 Cron.Info 192.168.4.200 May 27 14:43:00 /usr/sbin/cron[34769]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:43:01 User.Debug 192.168.4.200 May 27 14:43:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:43:01 User.Debug 192.168.4.200 May 27 14:43:01 manage.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:43:03 User.Debug 192.168.4.200 May 27 14:43:01 manage.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:43:03 User.Debug 192.168.4.200 May 27 14:43:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:43:03 User.Debug 192.168.4.200 May 27 14:43:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34769 2014-05-27 14:43:03 User.Debug 192.168.4.200 May 27 14:43:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:44:00 Cron.Info 192.168.4.200 May 27 14:44:00 /usr/sbin/cron[34815]: (operator) CMD (/usr/libexec/save-entropy) 2014-05-27 14:44:00 Cron.Info 192.168.4.200 May 27 14:44:00 /usr/sbin/cron[34816]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:44:01 User.Debug 192.168.4.200 May 27 14:44:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:44:04 User.Debug 192.168.4.200 May 27 14:44:04 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:44:04 User.Debug 192.168.4.200 May 27 14:44:04 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34816 2014-05-27 14:44:04 User.Debug 192.168.4.200 May 27 14:44:04 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:45:00 Cron.Info 192.168.4.200 May 27 14:45:00 /usr/sbin/cron[34853]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/alert.py > /dev/null 2>&1) 2014-05-27 14:45:00 Cron.Info 192.168.4.200 May 27 14:45:00 /usr/sbin/cron[34852]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:45:00 Cron.Info 192.168.4.200 May 27 14:45:00 /usr/sbin/cron[34854]: (root) CMD (/usr/libexec/atrun) 2014-05-27 14:45:01 User.Debug 192.168.4.200 May 27 14:45:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:45:01 User.Debug 192.168.4.200 May 27 14:45:01 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:45:03 User.Debug 192.168.4.200 May 27 14:45:01 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:45:03 User.Debug 192.168.4.200 May 27 14:45:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:45:03 User.Debug 192.168.4.200 May 27 14:45:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34852 2014-05-27 14:45:03 User.Debug 192.168.4.200 May 27 14:45:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:46:00 Cron.Info 192.168.4.200 May 27 14:46:00 /usr/sbin/cron[34906]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:46:01 User.Debug 192.168.4.200 May 27 14:46:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:46:04 User.Debug 192.168.4.200 May 27 14:46:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:46:04 User.Debug 192.168.4.200 May 27 14:46:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34906 2014-05-27 14:46:04 User.Debug 192.168.4.200 May 27 14:46:04 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:46:10 System1.Info 192.168.4.200 May 27 14:46:10 proftpd[34928]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:46:10 System1.Notice 192.168.4.200 May 27 14:46:10 proftpd[34928]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER anonymous: no such user found from 24.73.96.230 [24.73.96.230] to ::ffff:192.168.4.200:21 2014-05-27 14:46:10 System1.Info 192.168.4.200 May 27 14:46:10 proftpd[34928]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:46:10 System1.Info 192.168.4.200 May 27 14:46:10 proftpd[34929]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:46:10 System1.Notice 192.168.4.200 May 27 14:46:10 proftpd[34929]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER anonymous: no such user found from 24.73.96.230 [24.73.96.230] to ::ffff:192.168.4.200:21 2014-05-27 14:46:10 System1.Info 192.168.4.200 May 27 14:46:10 proftpd[34929]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:46:15 System1.Info 192.168.4.200 May 27 14:46:15 proftpd[34932]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:46:15 System1.Info 192.168.4.200 May 27 14:46:15 proftpd[34932]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Preparing to chroot to directory '/mnt/New_Tampa/tampa' 2014-05-27 14:46:15 System1.Notice 192.168.4.200 May 27 14:46:15 proftpd[34932]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER jpatron: Login successful. 2014-05-27 14:46:15 System1.Info 192.168.4.200 May 27 14:46:15 proftpd[34932]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:46:15 System1.Info 192.168.4.200 May 27 14:46:15 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:46:15 System1.Info 192.168.4.200 May 27 14:46:15 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Preparing to chroot to directory '/mnt/New_Tampa/tampa' 2014-05-27 14:46:15 System1.Notice 192.168.4.200 May 27 14:46:15 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER jpatron: Login successful. 2014-05-27 14:46:15 System1.Debug 192.168.4.200 May 27 14:46:15 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Reallocating sreaddir buffer from 14 entries to 28 entries 2014-05-27 14:46:23 System1.Debug 192.168.4.200 May 27 14:46:22 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Reallocating sreaddir buffer from 16 entries to 32 entries 2014-05-27 14:46:26 Daemon.Error 192.168.4.200 May 27 14:46:26 winbindd[34938]: [2014/05/27 14:46:26.000765, 0, pid=34938, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:46:26 System4.Info 192.168.4.200 May 27 14:46:26 kernel: May 27 14:46:26 freenas winbindd[34938]: [2014/05/27 14:46:26.000765, 0, pid=34938, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:46:26 Daemon.Error 192.168.4.200 May 27 14:46:26 winbindd[34938]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:46:26 System4.Info 192.168.4.200 May 27 14:46:26 kernel: May 27 14:46:26 freenas winbindd[34938]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:46:37 Daemon.Error 192.168.4.200 May 27 14:46:37 winbindd[34944]: [2014/05/27 14:46:37.466692, 0, pid=34944, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:46:37 System4.Info 192.168.4.200 May 27 14:46:37 kernel: May 27 14:46:37 freenas winbindd[34944]: [2014/05/27 14:46:37.466692, 0, pid=34944, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:46:37 Daemon.Error 192.168.4.200 May 27 14:46:37 winbindd[34944]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:46:37 System4.Info 192.168.4.200 May 27 14:46:37 kernel: May 27 14:46:37 freenas winbindd[34944]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: [2014/05/27 14:46:40.481970, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: [2014/05/27 14:46:40.481970, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: [2014/05/27 14:46:40.637818, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: [2014/05/27 14:46:40.637818, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: [2014/05/27 14:46:40.668127, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: [2014/05/27 14:46:40.668127, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1010 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1010 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: [2014/05/27 14:46:40.668654, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: [2014/05/27 14:46:40.668654, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: [2014/05/27 14:46:40.669194, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: [2014/05/27 14:46:40.669194, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: [2014/05/27 14:46:40.669701, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: [2014/05/27 14:46:40.669701, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:46:40 Daemon.Error 192.168.4.200 May 27 14:46:40 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:46:40 System4.Info 192.168.4.200 May 27 14:46:40 kernel: May 27 14:46:40 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:47:00 Cron.Info 192.168.4.200 May 27 14:47:00 /usr/sbin/cron[34955]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:47:01 User.Debug 192.168.4.200 May 27 14:47:00 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:47:03 User.Debug 192.168.4.200 May 27 14:47:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:47:03 User.Debug 192.168.4.200 May 27 14:47:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34955 2014-05-27 14:47:03 User.Debug 192.168.4.200 May 27 14:47:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:47:07 System1.Debug 192.168.4.200 May 27 14:47:07 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Reallocating sreaddir buffer from 17 entries to 34 entries 2014-05-27 14:48:00 Cron.Info 192.168.4.200 May 27 14:48:00 /usr/sbin/cron[34985]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:48:01 User.Debug 192.168.4.200 May 27 14:48:01 manage.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:48:01 User.Debug 192.168.4.200 May 27 14:48:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:48:01 User.Debug 192.168.4.200 May 27 14:48:01 manage.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:48:04 User.Debug 192.168.4.200 May 27 14:48:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:48:04 User.Debug 192.168.4.200 May 27 14:48:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-34985 2014-05-27 14:48:04 User.Debug 192.168.4.200 May 27 14:48:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:48:40 Daemon.Error 192.168.4.200 May 27 14:48:39 winbindd[35019]: [2014/05/27 14:48:39.888397, 0, pid=35019, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:48:40 System4.Info 192.168.4.200 May 27 14:48:39 kernel: May 27 14:48:39 freenas winbindd[35019]: [2014/05/27 14:48:39.888397, 0, pid=35019, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:48:40 Daemon.Error 192.168.4.200 May 27 14:48:39 winbindd[35019]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:48:40 System4.Info 192.168.4.200 May 27 14:48:39 kernel: May 27 14:48:39 freenas winbindd[35019]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:48:51 Daemon.Error 192.168.4.200 May 27 14:48:51 winbindd[35034]: [2014/05/27 14:48:51.304505, 0, pid=35034, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:48:51 System4.Info 192.168.4.200 May 27 14:48:51 kernel: May 27 14:48:51 freenas winbindd[35034]: [2014/05/27 14:48:51.304505, 0, pid=35034, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:48:51 Daemon.Error 192.168.4.200 May 27 14:48:51 winbindd[35034]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:48:51 System4.Info 192.168.4.200 May 27 14:48:51 kernel: May 27 14:48:51 freenas winbindd[35034]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:49:01 Cron.Info 192.168.4.200 May 27 14:49:00 /usr/sbin/cron[35039]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:49:01 Daemon.Error 192.168.4.200 May 27 14:49:01 winbindd[35041]: [2014/05/27 14:49:01.121433, 0, pid=35041, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:49:01 System4.Info 192.168.4.200 May 27 14:49:01 kernel: May 27 14:49:01 freenas winbindd[35041]: [2014/05/27 14:49:01.121433, 0, pid=35041, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:49:01 Daemon.Error 192.168.4.200 May 27 14:49:01 winbindd[35041]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:49:01 System4.Info 192.168.4.200 May 27 14:49:01 kernel: May 27 14:49:01 freenas winbindd[35041]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:49:02 User.Debug 192.168.4.200 May 27 14:49:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:49:04 User.Debug 192.168.4.200 May 27 14:49:04 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:49:04 User.Debug 192.168.4.200 May 27 14:49:04 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35039 2014-05-27 14:49:04 User.Debug 192.168.4.200 May 27 14:49:04 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:49:34 Daemon.Error 192.168.4.200 May 27 14:49:34 winbindd[35077]: [2014/05/27 14:49:34.380817, 0, pid=35077, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:49:34 System4.Info 192.168.4.200 May 27 14:49:34 kernel: May 27 14:49:34 freenas winbindd[35077]: [2014/05/27 14:49:34.380817, 0, pid=35077, effective(0, 0), real(0, 0)] ../lib/util/pidfile.c:110(pidfile_create) 2014-05-27 14:49:34 Daemon.Error 192.168.4.200 May 27 14:49:34 winbindd[35077]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:49:34 System4.Info 192.168.4.200 May 27 14:49:34 kernel: May 27 14:49:34 freenas winbindd[35077]: ERROR: winbindd is already running. File /var/run/samba/winbindd.pid exists and process id 34671 is running. 2014-05-27 14:50:00 Cron.Info 192.168.4.200 May 27 14:50:00 /usr/sbin/cron[35096]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/alert.py > /dev/null 2>&1) 2014-05-27 14:50:00 Cron.Info 192.168.4.200 May 27 14:50:00 /usr/sbin/cron[35097]: (root) CMD (/usr/libexec/atrun) 2014-05-27 14:50:00 Cron.Info 192.168.4.200 May 27 14:50:00 /usr/sbin/cron[35098]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:50:01 User.Debug 192.168.4.200 May 27 14:50:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:50:01 User.Debug 192.168.4.200 May 27 14:50:01 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:50:03 User.Debug 192.168.4.200 May 27 14:50:01 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:50:03 User.Debug 192.168.4.200 May 27 14:50:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:50:03 User.Debug 192.168.4.200 May 27 14:50:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35098 2014-05-27 14:50:03 User.Debug 192.168.4.200 May 27 14:50:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: [2014/05/27 14:50:17.122549, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: [2014/05/27 14:50:17.122549, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: [2014/05/27 14:50:17.556856, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: [2014/05/27 14:50:17.556856, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: [2014/05/27 14:50:17.586801, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: [2014/05/27 14:50:17.586801, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: [2014/05/27 14:50:17.587359, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: [2014/05/27 14:50:17.587359, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: [2014/05/27 14:50:17.587868, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: [2014/05/27 14:50:17.587868, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: [2014/05/27 14:50:17.588874, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: [2014/05/27 14:50:17.588874, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:50:17 Daemon.Error 192.168.4.200 May 27 14:50:17 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1009 2014-05-27 14:50:17 System4.Info 192.168.4.200 May 27 14:50:17 kernel: May 27 14:50:17 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1009 2014-05-27 14:50:28 System1.Info 192.168.4.200 May 27 14:50:28 proftpd[34933]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:51:01 Cron.Info 192.168.4.200 May 27 14:51:00 /usr/sbin/cron[35157]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:51:01 User.Debug 192.168.4.200 May 27 14:51:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:51:04 User.Debug 192.168.4.200 May 27 14:51:04 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:51:04 User.Debug 192.168.4.200 May 27 14:51:04 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35157 2014-05-27 14:51:04 User.Debug 192.168.4.200 May 27 14:51:04 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:52:00 Cron.Info 192.168.4.200 May 27 14:52:00 /usr/sbin/cron[35187]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:52:01 User.Debug 192.168.4.200 May 27 14:52:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:52:03 User.Debug 192.168.4.200 May 27 14:52:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:52:03 User.Debug 192.168.4.200 May 27 14:52:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35187 2014-05-27 14:52:03 User.Debug 192.168.4.200 May 27 14:52:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:52:27 Daemon.Error 192.168.4.200 May 27 14:52:27 winbindd[34674]: [2014/05/27 14:52:27.610049, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:52:27 System4.Info 192.168.4.200 May 27 14:52:27 kernel: May 27 14:52:27 freenas winbindd[34674]: [2014/05/27 14:52:27.610049, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:52:27 Daemon.Error 192.168.4.200 May 27 14:52:27 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:52:27 System4.Info 192.168.4.200 May 27 14:52:27 kernel: May 27 14:52:27 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:53:00 Cron.Info 192.168.4.200 May 27 14:53:00 /usr/sbin/cron[35222]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:53:01 User.Debug 192.168.4.200 May 27 14:53:01 manage.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:53:01 User.Debug 192.168.4.200 May 27 14:53:01 manage.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:53:01 User.Debug 192.168.4.200 May 27 14:53:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:53:04 User.Debug 192.168.4.200 May 27 14:53:04 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:53:04 User.Debug 192.168.4.200 May 27 14:53:04 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35222 2014-05-27 14:53:04 User.Debug 192.168.4.200 May 27 14:53:04 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: [2014/05/27 14:53:25.326910, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: [2014/05/27 14:53:25.326910, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:769(sam_rids_to_names) 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: sam_rids_to_names: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: [2014/05/27 14:53:25.355826, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: [2014/05/27 14:53:25.355826, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1002 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: [2014/05/27 14:53:25.356439, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: [2014/05/27 14:53:25.356439, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1008 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: [2014/05/27 14:53:25.357099, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: [2014/05/27 14:53:25.357099, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1004 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: [2014/05/27 14:53:25.357720, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: [2014/05/27 14:53:25.357720, 0, pid=34674, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_samr.c:694(sam_sid_to_name) 2014-05-27 14:53:25 Daemon.Error 192.168.4.200 May 27 14:53:25 winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1009 2014-05-27 14:53:25 System4.Info 192.168.4.200 May 27 14:53:25 kernel: May 27 14:53:25 freenas winbindd[34674]: sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-21-2803706266-3940992467-408568249-1009 2014-05-27 14:54:00 Cron.Info 192.168.4.200 May 27 14:54:00 /usr/sbin/cron[35269]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:54:01 User.Debug 192.168.4.200 May 27 14:54:00 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:54:03 User.Debug 192.168.4.200 May 27 14:54:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:54:03 User.Debug 192.168.4.200 May 27 14:54:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35269 2014-05-27 14:54:03 User.Debug 192.168.4.200 May 27 14:54:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:55:00 Cron.Info 192.168.4.200 May 27 14:55:00 /usr/sbin/cron[35302]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:55:00 Cron.Info 192.168.4.200 May 27 14:55:00 /usr/sbin/cron[35305]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/alert.py > /dev/null 2>&1) 2014-05-27 14:55:00 Cron.Info 192.168.4.200 May 27 14:55:00 /usr/sbin/cron[35306]: (root) CMD (/usr/libexec/atrun) 2014-05-27 14:55:00 Cron.Info 192.168.4.200 May 27 14:55:00 /usr/sbin/cron[35304]: (operator) CMD (/usr/libexec/save-entropy) 2014-05-27 14:55:01 User.Debug 192.168.4.200 May 27 14:55:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:55:01 User.Debug 192.168.4.200 May 27 14:55:01 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:55:03 User.Debug 192.168.4.200 May 27 14:55:01 alert.py: [middleware.notifier:220] Popen()ing: zpool list -H -o health New_Tampa 2014-05-27 14:55:03 User.Debug 192.168.4.200 May 27 14:55:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:55:03 User.Debug 192.168.4.200 May 27 14:55:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35302 2014-05-27 14:55:03 User.Debug 192.168.4.200 May 27 14:55:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:55:39 System1.Info 192.168.4.200 May 27 14:55:38 proftpd[35357]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:55:39 System1.Notice 192.168.4.200 May 27 14:55:38 proftpd[35357]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER anonymous: no such user found from 24.73.96.230 [24.73.96.230] to ::ffff:192.168.4.200:21 2014-05-27 14:55:39 System1.Info 192.168.4.200 May 27 14:55:38 proftpd[35357]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:55:44 System1.Info 192.168.4.200 May 27 14:55:44 proftpd[35358]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:55:44 System1.Info 192.168.4.200 May 27 14:55:44 proftpd[35358]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Preparing to chroot to directory '/mnt/New_Tampa/tampa' 2014-05-27 14:55:44 System1.Notice 192.168.4.200 May 27 14:55:44 proftpd[35358]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER jpatron: Login successful. 2014-05-27 14:55:44 System1.Info 192.168.4.200 May 27 14:55:44 proftpd[35358]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:55:44 System1.Info 192.168.4.200 May 27 14:55:44 proftpd[35359]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session opened. 2014-05-27 14:55:44 System1.Info 192.168.4.200 May 27 14:55:44 proftpd[35359]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Preparing to chroot to directory '/mnt/New_Tampa/tampa' 2014-05-27 14:55:44 System1.Notice 192.168.4.200 May 27 14:55:44 proftpd[35359]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - USER jpatron: Login successful. 2014-05-27 14:55:44 System1.Debug 192.168.4.200 May 27 14:55:44 proftpd[35359]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Reallocating sreaddir buffer from 14 entries to 28 entries 2014-05-27 14:55:51 System1.Debug 192.168.4.200 May 27 14:55:50 proftpd[35359]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - Reallocating sreaddir buffer from 17 entries to 34 entries 2014-05-27 14:56:01 Cron.Info 192.168.4.200 May 27 14:56:00 /usr/sbin/cron[35367]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:56:01 User.Debug 192.168.4.200 May 27 14:56:01 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:56:04 User.Debug 192.168.4.200 May 27 14:56:04 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:56:04 User.Debug 192.168.4.200 May 27 14:56:04 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35367 2014-05-27 14:56:04 User.Debug 192.168.4.200 May 27 14:56:04 autorepl.py: [tools.autorepl:393] Autosnap replication finished 2014-05-27 14:56:48 System1.Info 192.168.4.200 May 27 14:56:48 proftpd[35359]: 127.0.0.1 (24.73.96.230[24.73.96.230]) - FTP session closed. 2014-05-27 14:57:00 Cron.Info 192.168.4.200 May 27 14:57:00 /usr/sbin/cron[35397]: (root) CMD (/usr/local/bin/python /usr/local/www/freenasUI/tools/autosnap.py > /dev/null 2>&1) 2014-05-27 14:57:01 User.Debug 192.168.4.200 May 27 14:57:00 autosnap.py: [tools.autosnap:58] Popen()ing: /sbin/zfs list -t snapshot -H 2014-05-27 14:57:03 User.Debug 192.168.4.200 May 27 14:57:03 autorepl.py: [tools.autorepl:117] Autosnap replication started 2014-05-27 14:57:03 User.Debug 192.168.4.200 May 27 14:57:03 autorepl.py: [tools.autorepl:118] temp log file: /tmp/repl-35397 2014-05-27 14:57:03 User.Debug 192.168.4.200 May 27 14:57:03 autorepl.py: [tools.autorepl:393] Autosnap replication finished