October 8, 201411 yr I was working in a deluge docker, it wasn't cooperating, so I thought I'd reinstall the docker, to see if that would 'trick' it into working for me. From the docker page, I hit the update link (it didn't need to be updated, but that's a fast way to force it to reload the container). The GUI just disappeared, and said it was not available. I have the tail of the syslog in a new window... Oct 8 13:50:10 media kernel: ata10: exception Emask 0x10 SAct 0x0 SErr 0x4090000 action 0xe frozen Oct 8 13:50:10 media kernel: ata10: irq_stat 0x00400040, connection status changed Oct 8 13:50:10 media kernel: ata10: SError: { PHYRdyChg 10B8B DevExch } Oct 8 13:50:10 media kernel: ata10: hard resetting link Oct 8 13:50:16 media kernel: ata10: SATA link up 1.5 Gbps (SStatus 113 SControl 310) Oct 8 13:50:16 media kernel: ata10.00: ACPI cmd ef/10:06:00:00:00:00 (SET FEATURES) succeeded Oct 8 13:50:16 media kernel: ata10.00: ACPI cmd f5/00:00:00:00:00:00 (SECURITY FREEZE LOCK) filtered out Oct 8 13:50:16 media kernel: ata10.00: ACPI cmd b1/c1:00:00:00:00:00 (DEVICE CONFIGURATION OVERLAY) filtered out Oct 8 13:50:16 media kernel: ata10.00: ACPI cmd ef/10:06:00:00:00:00 (SET FEATURES) succeeded Oct 8 13:50:16 media kernel: ata10.00: ACPI cmd f5/00:00:00:00:00:00 (SECURITY FREEZE LOCK) filtered out Oct 8 13:50:16 media kernel: ata10.00: ACPI cmd b1/c1:00:00:00:00:00 (DEVICE CONFIGURATION OVERLAY) filtered out Oct 8 13:50:16 media kernel: ata10.00: configured for UDMA/33 Oct 8 13:50:16 media kernel: ata10: EH complete Oct 8 13:51:10 media kernel: mdcmd (53): spindown 4 Oct 8 13:56:40 media kernel: mdcmd (54): spindown 5 Oct 8 14:02:40 media kernel: mdcmd (55): spindown 2 Oct 8 14:03:41 media kernel: mdcmd (56): spindown 8 Oct 8 14:22:02 media kernel: mdcmd (57): spindown 9 Oct 8 14:23:02 media kernel: mdcmd (58): spindown 10 Oct 8 14:26:22 media kernel: mdcmd (59): spindown 3 Oct 8 14:34:03 media kernel: mdcmd (60): spindown 8 Oct 8 14:38:43 media kernel: mdcmd (61): spindown 7 Oct 8 15:03:13 media emhttp: read_line: read_line: input line too long Oct 8 15:03:22 media emhttp: read_line: read_line: input line too long Oct 8 15:03:22 media emhttp: read_line: read_line: input line too long Oct 8 15:03:22 media emhttp: read_line: read_line: input line too long Oct 8 15:03:22 media emhttp: read_line: read_line: input line too long Oct 8 15:03:22 media emhttp: read_line: read_line: input line too long Oct 8 15:03:22 media emhttp: read_line: read_line: input line too long Oct 8 15:03:23 media emhttp: read_line: read_line: input line too long Oct 8 15:03:23 media emhttp: read_line: read_line: input line too long Oct 8 15:03:24 media emhttp: read_line: read_line: input line too long Oct 8 15:03:27 media emhttp: read_line: read_line: input line too long Oct 8 15:03:31 media emhttp: read_line: read_line: input line too long Oct 8 15:03:33 media emhttp: read_line: read_line: input line too long Oct 8 15:03:33 media emhttp: read_line: read_line: input line too long Oct 8 15:03:51 media emhttp: read_line: read_line: input line too long Oct 8 15:03:57 media emhttp: read_line: read_line: input line too long Oct 8 15:04:23 media emhttp: read_line: read_line: input line too long Oct 8 15:04:54 media sshd[15088]: Accepted password for root from 192.168.20.134 port 52692 ssh2 The last line was me logging in via putty, to see if it was still running. it is.
October 8, 201411 yr Justin....get a smart report on that hard drive. It sounds like it might be dying.
October 8, 201411 yr I received the same messages emhttp: read_line: read_line: input line too long when trying to use deluge via a plugin or docker. I messaged Tom at the time and he said that he would have to enable something to figure out why / what the message meant but I don't think he ever did. I ended up giving up trying to install Deluge as a plugin or docker and have been running Deluge under an Ubuntu VM and it has been solid for 2+ months now.
October 8, 201411 yr Author Justin....get a smart report on that hard drive. It sounds like it might be dying. which hard drive? ata10? it's my parity drive. if that drive is dying, I will literally take my server apart, sell off the pieces, and never have a server again. I have literally spent hundreds of hours over the last several weeks fighting this damn thing, and I am seriously at the end of my rope with it.
October 8, 201411 yr Author I received the same messages emhttp: read_line: read_line: input line too long when trying to use deluge via a plugin or docker. I messaged Tom at the time and he said that he would have to enable something to figure out why / what the message meant but I don't think he ever did. I ended up giving up trying to install Deluge as a plugin or docker and have been running Deluge under an Ubuntu VM and it has been solid for 2+ months now. I'll forward this link to jonp and see if he/they have, or can take another look. thanks
October 8, 201411 yr I found Tom's Post: http://lime-technology.com/forum/index.php?topic=33822.msg317677#msg317677 I recently installed Deulge and once is it installed unRAID gives the following errors: Jul 16 14:03:48 Tower emhttp: read_line: read_line: input line too long Jul 16 14:04:23 Tower last message repeated 15 times Jul 16 14:04:27 Tower last message repeated 7 times Once this happens I lose the option to connect to the unRAID Gui via http://Tower. I have to enter the IP address (192.168.1.20) to pull up the unRAID web Gui. This also happens if I install the Deluge_64.plg so it would appear that this is not a docker problem but I was hoping that some else here was running into similar issues? The 'read_line' function is used to read CRLF-terminated lines sent by the browser during an http request. The limits are set up like this: #define LINE_SIZE 1024 /* from apache: MAX_HEADER_SIZE=1024 */ #define INBUF_SIZE (LINE_SIZE + 3072) /* handle largest GET message */ When reading the initial GET, emhttp uses INBUF_SIZE buffer. When reading additional header lines it uses LINE_SIZE buffer. Unfortunately I didn't add the buffer size parameter to the error message so I can't tell which buffer is filling up. We will try and reproduce this, and I will add additional debug output in next release. That should help.
October 8, 201411 yr Author even starting in safe mode doesn't work. I'm completely unable to get into the GUI, which means I can't turn or, nor uninstall Deluge. My server is useless at this point!
October 8, 201411 yr Can you use the IP address to access the server and have you tried another browser/computer?
October 8, 201411 yr Author Can you use the IP address to access the server and have you tried another browser/computer? I ended up trying IE, and that was able to connect to the server GUI. I then had to reset all my cookies in Firefox and it's now able to connect also. I removed deluge, and have restarted, but during that process, my parity drive red-balled and my syslog indicates yet another drive is having issues. I'm so close to doing EXACTLY what your GIF shows. I just don't have the time money and energy to keep fighting this stupid computer. I suspect it's the universe's way of telling me to stop watching so much TV and go outside more. I should just listen.
October 8, 201411 yr Can you use the IP address to access the server and have you tried another browser/computer? I ended up trying IE, and that was able to connect to the server GUI. I then had to reset all my cookies in Firefox and it's now able to connect also. I removed deluge, and have restarted, but during that process, my parity drive red-balled and my syslog indicates yet another drive is having issues. I'm so close to doing EXACTLY what your GIF shows. I just don't have the time money and energy to keep fighting this stupid computer. I suspect it's the universe's way of telling me to stop watching so much TV and go outside more. I should just listen. FWIW I sounds like you could use a week or so without messing with the server. It might be advisable to keep it turned off for a week or so and just forget about it for awhile (I'm sure taking a hammer to it sounds enjoyable now but you would probably regret it later). I know after 2 weeks of messing with a server I would need a break. If I was facing the same situation, I would probably leave the server along for a week, then consider going back to a fresh copy of unRAID v5 (unfortunately you would need to convert the drives back to reiserfs). Then after a week of it not giving me any problems I would start to install plugins again. Again that is just me (I can get pretty crazy and go to extremes... )
October 10, 201411 yr It would help in this case to make a small change in go file: /usr/local/sbin/emhttp & to /usr/local/sbin/emhttp -d2 & And then reboot. Once server is back up, make the problem happen and then post your system log. Then edit 'go' file again and remove the option. This will cause a lot of debugging info to be generated in the system log by http requests.
October 11, 201411 yr Author Okay, here are syslogs on a similar problem. Sometimes, I lose connection to th internet, my router, the server, everything. it happens when the server is downloading lots of data. I was testing for the GUI issue, but then I lost the connection to the router, it just wouldn't let me connect to anything, then lost the ability to connect to the router at all. the lights for the ethernet connections to the router were blinking REALLY fast, so I assumed the server was overwhelming the router. I disconnected the cables from the server, and my laptop could connect just fine again. i reconnected the cables, and within a minute or so, I lost connection again. disconnect, connection restored, reconnect, stopped SAB and Deluge, and I still have connection. Syslog attached. I really hope they help fix this issue. syslog.zip
October 11, 201411 yr Okay, here are syslogs on a similar problem. Sometimes, I lose connection to th internet, my router, the server, everything. it happens when the server is downloading lots of data. I was testing for the GUI issue, but then I lost the connection to the router, it just wouldn't let me connect to anything, then lost the ability to connect to the router at all. the lights for the ethernet connections to the router were blinking REALLY fast, so I assumed the server was overwhelming the router. I disconnected the cables from the server, and my laptop could connect just fine again. i reconnected the cables, and within a minute or so, I lost connection again. disconnect, connection restored, reconnect, stopped SAB and Deluge, and I still have connection. Syslog attached. I really hope they help fix this issue. This may just be an issue with the router not being able to cope with the load. I have hear frequent reports of home routers failing to behave properly when under heavy load. Do you have any alternative router you can try?
October 11, 201411 yr Justin, Want to see if we can help figure this out, but getting a little lost on exactly how you ended up in this state. Let's run down the list at this point: 1) Can you get the server up and webGui accessible at all at this point or have you had no access to the unRAID webGui since you reported this issue on the 8th? 2) You still can get to command line though and thus are able to copy over syslogs, yes? 3) Can you also still connect to the server over SMB (connecting from a PC to the shares)? 4) Is this perhaps also related to your networking issue with the address being reset because of the change you made to your go file?
October 11, 201411 yr Author This may just be an issue with the router not being able to cope with the load. I have hear frequent reports of home routers failing to behave properly when under heavy load. Do you have any alternative router you can try? I have considered this possibility. Every time I've checked the router, it's used less than 60% of available memory, so I'm leaning towards it NOT being the router, but can't positively rule it out either. I have another router that I bought for another purpose, and have never opened, and was planning on selling it; but it we come to the conclusion it's the current router, I'll crack it open and give it a shot. I'll also check for an updated Tomato build, in case this is a firmware problem instead of a router problem. I never had these problems with this router on unraid version 5 with an older firmware version, but shortly after moving to version 6, I updated the router firmware because I started having issues. Justin, Want to see if we can help figure this out, but getting a little lost on exactly how you ended up in this state. Let's run down the list at this point: 1) Can you get the server up and webGui accessible at all at this point or have you had no access to the unRAID webGui since you reported this issue on the 8th? 2) You still can get to command line though and thus are able to copy over syslogs, yes? 3) Can you also still connect to the server over SMB (connecting from a PC to the shares)? 4) Is this perhaps also related to your networking issue with the address being reset because of the change you made to your go file? I appreciate it!! i will admit, it seems this is 2 different problems. the GUI was lost, but everything else on my system worked fine when I created this post. Earlier today, when testing for this problem, I lost all access on my computer, and only unplugging the ethernet cables restored my access. this second issue may be router related, but i'm not sure. I'll try to reproduce the GUI freeze/lockout issue in this thread, and if I have other full lockout issues, I'll create a new post for that issue, to track separately. 1) I can get to the GUI just fine right now 2) I can get into command line just fine right now, and usually when the GUI stops responding. 3) Yes, I was able to connect to shares just fine when the GUI froze 4) I don't think it's related to the networking issue; but can't say for certain. I'll start deluge, and start downloading with it, and see if this issue returns. First, I'm going to reboot with the -d in the go file settings, in case it does happen. Will report back when I have more info.
October 11, 201411 yr Justin, Want to see if we can help figure this out, but getting a little lost on exactly how you ended up in this state. Let's run down the list at this point: 1) Can you get the server up and webGui accessible at all at this point or have you had no access to the unRAID webGui since you reported this issue on the 8th? 2) You still can get to command line though and thus are able to copy over syslogs, yes? 3) Can you also still connect to the server over SMB (connecting from a PC to the shares)? 4) Is this perhaps also related to your networking issue with the address being reset because of the change you made to your go file? I appreciate it!! i will admit, it seems this is 2 different problems. the GUI was lost, but everything else on my system worked fine when I created this post. Earlier today, when testing for this problem, I lost all access on my computer, and only unplugging the ethernet cables restored my access. this second issue may be router related, but i'm not sure. I'll try to reproduce the GUI freeze/lockout issue in this thread, and if I have other full lockout issues, I'll create a new post for that issue, to track separately. 1) I can get to the GUI just fine right now 2) I can get into command line just fine right now, and usually when the GUI stops responding. 3) Yes, I was able to connect to shares just fine when the GUI froze 4) I don't think it's related to the networking issue; but can't say for certain. I'll start deluge, and start downloading with it, and see if this issue returns. First, I'm going to reboot with the -d in the go file settings, in case it does happen. Will report back when I have more info. Ok. The lack of consistency in the issue is making it difficult to diagnose and troubleshoot, but let us know if the issues persist.
October 11, 201411 yr Author I understand, and believe me, I wish i didn't have multiple simultaneous issues, i REALLY do. With that said, I enabled the -d2 switch in the go file, rebooted, turned on deluge, unpaused 2 torrents, neither downloads very fast, since I have QOS enabled in the router, so maybe 1MB/min total, if that. Within about a minute, the internet became very unresponsive. the unRAID GUI kept working, but I couldn't browse to other websites. I didn't lose the connection to the router, so I was able to keep my connection to unRAID. I grabbed the syslog, stopped the array, rebooted the server, and internet is just fine again. This is definitely an issue with unRAID and it overwhelming the router, somehow. Hopefully the syslog sheds some light on what's happening. If not, please let me know what I can test next. Thanks for looking into this. syslogslow.txt
October 11, 201411 yr I understand, and believe me, I wish i didn't have multiple simultaneous issues, i REALLY do. With that said, I enabled the -d2 switch in the go file, rebooted, turned on deluge, unpaused 2 torrents, neither downloads very fast, since I have QOS enabled in the router, so maybe 1MB/min total, if that. Within about a minute, the internet became very unresponsive. the unRAID GUI kept working, but I couldn't browse to other websites. I didn't lose the connection to the router, so I was able to keep my connection to unRAID. I grabbed the syslog, stopped the array, rebooted the server, and internet is just fine again. This is definitely an issue with unRAID and it overwhelming the router, somehow. Hopefully the syslog sheds some light on what's happening. If not, please let me know what I can test next. Thanks for looking into this. Post a screenshot of your current network settings. Also, do you have multiple NICs in your UnRAID server? Are the both connected or is only one nic connected?
October 11, 201411 yr Author Settings attached. I have both network connections on my motherboard connected. I have network bonding enabled also. As of a week or 2 ago, I noticed that one of the cables shows as 100MB, and the other as 1000MB; not sure why. Both are GB LAN, so I'd expect them to both connect at full speed, but it seems not. I just checked right now, and one of them shows as GB, and the other light isn't even lit. the router isn't showing a light for that cable now either. Not sure when this started. Please let me know what else I can test or provide.
October 12, 201411 yr Ok, for the sake of narrowing down issues here, can you disable NIC bonding and only use a single NIC for now? I just want to see if this resolves the issue and if so, we may have something to diagnose in NIC bonding.
October 12, 201411 yr Author I've turned off bonding, but have not yet rebooted. I just tried to go to the GUI, and it's locked up again. I don't have the -d2 switch in the go file at this time, so logging is probably not sufficient, but in case there is any clue in the syslog, here are the lines from when I turned off bonding, thru to my last 3 attempts to open the GUI. Oct 11 21:03:09 media emhttp: shcmd (82): /usr/local/sbin/emhttp_event stopping_svcs Oct 11 21:03:09 media emhttp_event: stopping_svcs Oct 11 21:03:09 media emhttp: shcmd (83): /etc/rc.d/rc.atalk status Oct 11 21:03:09 media emhttp: shcmd (84): pidof rpc.mountd &> /dev/null Oct 11 21:03:09 media emhttp: Stop NFS... Oct 11 21:03:09 media emhttp: shcmd (85): /etc/rc.d/rc.nfsd stop |& logger Oct 11 21:03:09 media rpc.mountd[6815]: Caught signal 15, un-registering and exiting. Oct 11 21:03:10 media emhttp: Stop SMB... Oct 11 21:03:10 media emhttp: shcmd (86): /etc/rc.d/rc.samba stop |& logger Oct 11 21:03:10 media kernel: nfsd: last server has exited, flushing export cache Oct 11 21:03:10 media emhttp: shcmd (87): rm /etc/avahi/services/smb.service &> /dev/null Oct 11 21:03:10 media emhttp: shcmd (88): /etc/rc.d/rc.inet1 stop Oct 11 21:03:10 media logger: /etc/rc.d/rc.inet1: List of interfaces: 'br0' Oct 11 21:03:10 media logger: /etc/rc.d/rc.inet1: /sbin/route del default Oct 11 21:03:10 media dhcpcd[1541]: br0: removing default route via 192.168.20.1 Oct 11 21:03:10 media logger: /etc/rc.d/rc.inet1: /sbin/dhcpcd -k -d br0 Oct 11 21:03:10 media dhcpcd[16337]: sending signal 1 to pid 1541 Oct 11 21:03:10 media dhcpcd[16337]: waiting for pid 1541 to exit Oct 11 21:03:10 media dhcpcd[1541]: received SIGHUP from PID 16337, releasing Oct 11 21:03:10 media dhcpcd[1541]: br0: removing interface Oct 11 21:03:10 media dhcpcd[1541]: br0: releasing lease of 192.168.20.150 Oct 11 21:03:10 media dhcpcd[1541]: br0: sending RELEASE with xid 0x2cc723f0 Oct 11 21:03:10 media dhcpcd[1541]: br0: deleting host route to 192.168.20.150 via 127.0.0.1 Oct 11 21:03:10 media dhcpcd[1541]: br0: deleting route to 192.168.20.0/24 Oct 11 21:03:10 media dhcpcd[1541]: br0: deleting IP address 192.168.20.150/24 Oct 11 21:03:10 media dhcpcd[1541]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOP Oct 11 21:03:10 media dhcpcd[1541]: exited Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: /sbin/brctl delif br0 bond0 Oct 11 21:03:11 media kernel: br0: port 1(bond0) entered disabled state Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig br0 down Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: /sbin/brctl delbr br0 Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: echo -eth1 > /sys/class/net/bond0/bonding/slaves Oct 11 21:03:11 media kernel: bonding: bond0: Removing slave eth1 Oct 11 21:03:11 media kernel: bonding: bond0: Releasing active interface eth1 Oct 11 21:03:11 media kernel: device eth1 left promiscuous mode Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig bond0 down Oct 11 21:03:11 media kernel: e1000e: eth1 NIC Link is Down Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: rmmod bonding Oct 11 21:03:11 media kernel: bonding: bond0: Released all slaves Oct 11 21:03:11 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig lo down Oct 11 21:03:13 media ntpd[1599]: Deleting interface #2 br0, 192.168.20.150#123, interface stats: received=207, sent=207, dropped=0, active_time=26735 secs Oct 11 21:03:13 media ntpd[1599]: 129.6.15.28 interface 192.168.20.150 -> (none) Oct 11 21:03:13 media ntpd[1599]: 128.138.141.172 interface 192.168.20.150 -> (none) Oct 11 21:03:13 media ntpd[1599]: Deleting interface #1 lo, 127.0.0.1#123, interface stats: received=3, sent=3, dropped=0, active_time=26743 secs Oct 11 21:03:13 media ntpd[1599]: 127.127.1.0 interface 127.0.0.1 -> (none) Oct 11 21:03:13 media ntpd[1599]: peers refreshed Oct 11 21:03:14 media emhttp: shcmd (89): /etc/rc.d/rc.inet1 start Oct 11 21:03:14 media logger: /etc/rc.d/rc.inet1: List of interfaces: 'br0' Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig lo 127.0.0.1 Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/route add -net 127.0.0.0 netmask 255.0.0.0 lo Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig eth1 down Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig eth1 0.0.0.0 promisc up Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/brctl addif br0 eth1 Oct 11 21:03:15 media kernel: device eth1 entered promiscuous mode Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/dhcpcd -t 10 -h media -d -L br0 Oct 11 21:03:15 media dhcpcd[16449]: version 6.0.5 starting Oct 11 21:03:15 media dhcpcd[16449]: forking to background Oct 11 21:03:15 media dhcpcd[16449]: forked to background, child pid 16450 Oct 11 21:03:15 media dhcpcd[16450]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT Oct 11 21:03:15 media logger: /etc/rc.d/rc.inet1: /sbin/route add default gw 192.168.20.1 metric 1 Oct 11 21:03:15 media logger: SIOCADDRT: Network is unreachable Oct 11 21:03:15 media emhttp: shcmd (90): :>/etc/samba/smb-shares.conf Oct 11 21:03:15 media emhttp: shcmd (91): cp /etc/exports- /etc/exports Oct 11 21:03:15 media emhttp: shcmd (92): echo '"/mnt/user/backup" -async,no_subtree_check,fsid=103 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:03:15 media emhttp: shcmd (93): echo '"/mnt/user/documents" -async,no_subtree_check,fsid=104 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:03:15 media emhttp: shcmd (94): echo '"/mnt/user/music" -async,no_subtree_check,fsid=106 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:03:15 media dhcpcd[16450]: br0: waiting for carrier Oct 11 21:03:15 media emhttp: shcmd (95): echo '"/mnt/user/photos" -async,no_subtree_check,fsid=107 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:03:15 media emhttp: shcmd (96): echo '"/mnt/user/video" -async,no_subtree_check,fsid=109 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:03:15 media emhttp: Start SMB... Oct 11 21:03:15 media emhttp: shcmd (97): /etc/rc.d/rc.samba start |& logger Oct 11 21:03:15 media logger: Starting Samba: /usr/sbin/nmbd -D Oct 11 21:03:15 media logger: /usr/sbin/smbd -D Oct 11 21:03:15 media emhttp: shcmd (98): cp /etc/avahi/services/smb.service- /etc/avahi/services/smb.service Oct 11 21:03:15 media emhttp: shcmd (99): pidof rpc.mountd &> /dev/null Oct 11 21:03:15 media emhttp: Start NFS... Oct 11 21:03:15 media emhttp: shcmd (100): /etc/rc.d/rc.nfsd start |& logger Oct 11 21:03:15 media logger: Starting NFS server daemons: Oct 11 21:03:15 media logger: /usr/sbin/exportfs -r Oct 11 21:03:15 media logger: /usr/sbin/rpc.nfsd 8 Oct 11 21:03:15 media logger: /usr/sbin/rpc.mountd Oct 11 21:03:15 media rpc.mountd[16514]: Version 1.2.8 starting Oct 11 21:03:15 media emhttp: shcmd (101): /etc/rc.d/rc.atalk status Oct 11 21:03:15 media emhttp: shcmd (102): /usr/local/sbin/emhttp_event svcs_restarted Oct 11 21:03:15 media emhttp_event: svcs_restarted Oct 11 21:03:17 media ntpd[1599]: Listen normally on 4 lo 127.0.0.1 UDP 123 Oct 11 21:03:17 media ntpd[1599]: peers refreshed Oct 11 21:03:17 media ntpd[1599]: new interface(s) found: waking up resolver Oct 11 21:03:18 media dhcpcd[16450]: br0: carrier acquired Oct 11 21:03:18 media dhcpcd[16450]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER Oct 11 21:03:18 media kernel: e1000e: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Oct 11 21:03:18 media kernel: br0: port 1(eth1) entered forwarding state Oct 11 21:03:18 media kernel: br0: port 1(eth1) entered forwarding state Oct 11 21:03:18 media dhcpcd[16450]: br0: using ClientID 01:bc:5f:f4:bc:17:55 Oct 11 21:03:18 media dhcpcd[16450]: br0: soliciting a DHCP lease Oct 11 21:03:18 media dhcpcd[16450]: br0: sending DISCOVER (xid 0x41e555bc), next in 3.40 seconds Oct 11 21:03:18 media dhcpcd[16450]: br0: offered 192.168.20.150 from 192.168.20.1 Oct 11 21:03:18 media dhcpcd[16450]: br0: sending REQUEST (xid 0x41e555bc), next in 4.08 seconds Oct 11 21:03:18 media dhcpcd[16450]: br0: acknowledged 192.168.20.150 from 192.168.20.1 Oct 11 21:03:18 media dhcpcd[16450]: br0: checking for 192.168.20.150 Oct 11 21:03:18 media dhcpcd[16450]: br0: sending ARP probe (1 of 3), next in 1.58 seconds Oct 11 21:03:20 media dhcpcd[16450]: br0: sending ARP probe (2 of 3), next in 1.78 seconds Oct 11 21:03:21 media dhcpcd[16450]: br0: sending ARP probe (3 of 3), next in 2.00 seconds Oct 11 21:03:23 media dhcpcd[16450]: br0: leased 192.168.20.150 for 86400 seconds Oct 11 21:03:23 media dhcpcd[16450]: br0: renew in 43200 seconds, rebind in 75600 seconds Oct 11 21:03:23 media dhcpcd[16450]: br0: adding IP address 192.168.20.150/24 Oct 11 21:03:23 media dhcpcd[16450]: br0: adding host route to 192.168.20.150 via 127.0.0.1 Oct 11 21:03:23 media dhcpcd[16450]: br0: adding route to 192.168.20.0/24 Oct 11 21:03:23 media dhcpcd[16450]: br0: adding default route via 192.168.20.1 Oct 11 21:03:23 media dhcpcd[16450]: br0: writing lease `/var/lib/dhcpcd/dhcpcd-br0.lease' Oct 11 21:03:23 media dhcpcd[16450]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' BOUND Oct 11 21:03:24 media dhcpcd[16450]: br0: sending ARP announce (1 of 2), next in 2.00 seconds Oct 11 21:03:25 media ntpd[1599]: Listen normally on 5 br0 192.168.20.150 UDP 123 Oct 11 21:03:25 media ntpd[1599]: peers refreshed Oct 11 21:03:25 media ntpd[1599]: new interface(s) found: waking up resolver Oct 11 21:03:26 media dhcpcd[16450]: br0: sending ARP announce (2 of 2) Oct 11 21:03:33 media kernel: br0: port 1(eth1) entered forwarding state Oct 11 21:12:38 media kernel: mdcmd (62): spindown 5 Oct 11 21:12:42 media emhttp: shcmd (103): /usr/local/sbin/emhttp_event stopping_svcs Oct 11 21:12:42 media emhttp_event: stopping_svcs Oct 11 21:12:42 media emhttp: shcmd (104): /etc/rc.d/rc.atalk status Oct 11 21:12:42 media emhttp: shcmd (105): pidof rpc.mountd &> /dev/null Oct 11 21:12:42 media emhttp: Stop NFS... Oct 11 21:12:42 media emhttp: shcmd (106): /etc/rc.d/rc.nfsd stop |& logger Oct 11 21:12:42 media rpc.mountd[16514]: Caught signal 15, un-registering and exiting. Oct 11 21:12:43 media kernel: nfsd: last server has exited, flushing export cache Oct 11 21:12:43 media emhttp: Stop SMB... Oct 11 21:12:43 media emhttp: shcmd (107): /etc/rc.d/rc.samba stop |& logger Oct 11 21:12:43 media emhttp: shcmd (108): rm /etc/avahi/services/smb.service &> /dev/null Oct 11 21:12:43 media emhttp: shcmd (109): /etc/rc.d/rc.inet1 stop Oct 11 21:12:43 media logger: /etc/rc.d/rc.inet1: List of interfaces: 'br0' Oct 11 21:12:43 media logger: /etc/rc.d/rc.inet1: /sbin/route del default Oct 11 21:12:43 media dhcpcd[16450]: br0: removing default route via 192.168.20.1 Oct 11 21:12:43 media logger: /etc/rc.d/rc.inet1: /sbin/dhcpcd -k -d br0 Oct 11 21:12:43 media dhcpcd[19352]: sending signal 1 to pid 16450 Oct 11 21:12:43 media dhcpcd[19352]: waiting for pid 16450 to exit Oct 11 21:12:43 media dhcpcd[16450]: received SIGHUP from PID 19352, releasing Oct 11 21:12:43 media dhcpcd[16450]: br0: removing interface Oct 11 21:12:43 media dhcpcd[16450]: br0: releasing lease of 192.168.20.150 Oct 11 21:12:43 media dhcpcd[16450]: br0: sending RELEASE with xid 0x2e65742d Oct 11 21:12:43 media dhcpcd[16450]: br0: deleting host route to 192.168.20.150 via 127.0.0.1 Oct 11 21:12:43 media dhcpcd[16450]: br0: deleting route to 192.168.20.0/24 Oct 11 21:12:43 media dhcpcd[16450]: br0: deleting IP address 192.168.20.150/24 Oct 11 21:12:43 media dhcpcd[16450]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOP Oct 11 21:12:43 media dhcpcd[16450]: exited Oct 11 21:12:44 media logger: /etc/rc.d/rc.inet1: /sbin/brctl delif br0 eth1 Oct 11 21:12:44 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig br0 down Oct 11 21:12:44 media kernel: br0: port 1(eth1) entered disabled state Oct 11 21:12:44 media logger: /etc/rc.d/rc.inet1: /sbin/brctl delbr br0 Oct 11 21:12:44 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig lo down Oct 11 21:12:46 media ntpd[1599]: Deleting interface #5 br0, 192.168.20.150#123, interface stats: received=15, sent=15, dropped=0, active_time=561 secs Oct 11 21:12:46 media ntpd[1599]: 129.6.15.28 interface 192.168.20.150 -> (none) Oct 11 21:12:46 media ntpd[1599]: 128.138.141.172 interface 192.168.20.150 -> (none) Oct 11 21:12:46 media ntpd[1599]: Deleting interface #4 lo, 127.0.0.1#123, interface stats: received=0, sent=0, dropped=0, active_time=569 secs Oct 11 21:12:46 media ntpd[1599]: 127.127.1.0 interface 127.0.0.1 -> (none) Oct 11 21:12:46 media ntpd[1599]: peers refreshed Oct 11 21:12:47 media emhttp: shcmd (110): /etc/rc.d/rc.inet1 start Oct 11 21:12:47 media logger: /etc/rc.d/rc.inet1: List of interfaces: 'br0' Oct 11 21:12:47 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig lo 127.0.0.1 Oct 11 21:12:47 media logger: /etc/rc.d/rc.inet1: /sbin/route add -net 127.0.0.0 netmask 255.0.0.0 lo Oct 11 21:12:47 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig eth1 down Oct 11 21:12:47 media logger: /etc/rc.d/rc.inet1: /sbin/ifconfig eth1 0.0.0.0 promisc up Oct 11 21:12:47 media kernel: e1000e: eth1 NIC Link is Down Oct 11 21:12:47 media logger: /etc/rc.d/rc.inet1: /sbin/brctl addif br0 eth1 Oct 11 21:12:48 media logger: /etc/rc.d/rc.inet1: /sbin/dhcpcd -t 10 -h media -d -L br0 Oct 11 21:12:48 media dhcpcd[19450]: version 6.0.5 starting Oct 11 21:12:48 media dhcpcd[19450]: forking to background Oct 11 21:12:48 media dhcpcd[19450]: forked to background, child pid 19451 Oct 11 21:12:48 media dhcpcd[19451]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT Oct 11 21:12:48 media logger: /etc/rc.d/rc.inet1: /sbin/route add default gw 192.168.20.1 metric 1 Oct 11 21:12:48 media logger: SIOCADDRT: Network is unreachable Oct 11 21:12:48 media emhttp: shcmd (111): :>/etc/samba/smb-shares.conf Oct 11 21:12:48 media emhttp: shcmd (112): cp /etc/exports- /etc/exports Oct 11 21:12:48 media emhttp: shcmd (113): echo '"/mnt/user/backup" -async,no_subtree_check,fsid=103 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:12:48 media emhttp: shcmd (114): echo '"/mnt/user/documents" -async,no_subtree_check,fsid=104 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:12:48 media emhttp: shcmd (115): echo '"/mnt/user/music" -async,no_subtree_check,fsid=106 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:12:48 media dhcpcd[19451]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER Oct 11 21:12:48 media emhttp: shcmd (116): echo '"/mnt/user/photos" -async,no_subtree_check,fsid=107 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:12:48 media emhttp: shcmd (117): echo '"/mnt/user/video" -async,no_subtree_check,fsid=109 *(sec=sys,rw,insecure,anongid=100,anonuid=99,all_squash)' >>/etc/exports Oct 11 21:12:48 media emhttp: Start SMB... Oct 11 21:12:48 media emhttp: shcmd (118): /etc/rc.d/rc.samba start |& logger Oct 11 21:12:48 media logger: Starting Samba: /usr/sbin/nmbd -D Oct 11 21:12:48 media dhcpcd[19451]: br0: using ClientID 01:bc:5f:f4:bc:17:55 Oct 11 21:12:48 media logger: /usr/sbin/smbd -D Oct 11 21:12:48 media emhttp: shcmd (119): cp /etc/avahi/services/smb.service- /etc/avahi/services/smb.service Oct 11 21:12:48 media emhttp: shcmd (120): pidof rpc.mountd &> /dev/null Oct 11 21:12:48 media emhttp: Start NFS... Oct 11 21:12:48 media emhttp: shcmd (121): /etc/rc.d/rc.nfsd start |& logger Oct 11 21:12:48 media dhcpcd[19451]: br0: soliciting a DHCP lease Oct 11 21:12:48 media dhcpcd[19451]: br0: sending DISCOVER (xid 0x750dfdef), next in 4.62 seconds Oct 11 21:12:48 media logger: Starting NFS server daemons: Oct 11 21:12:48 media logger: /usr/sbin/exportfs -r Oct 11 21:12:48 media logger: /usr/sbin/rpc.nfsd 8 Oct 11 21:12:48 media logger: /usr/sbin/rpc.mountd Oct 11 21:12:48 media rpc.mountd[19528]: Version 1.2.8 starting Oct 11 21:12:48 media emhttp: shcmd (122): /etc/rc.d/rc.atalk status Oct 11 21:12:48 media emhttp: shcmd (123): /usr/local/sbin/emhttp_event svcs_restarted Oct 11 21:12:48 media emhttp_event: svcs_restarted Oct 11 21:12:48 media dhcpcd[19451]: br0: carrier lost Oct 11 21:12:48 media dhcpcd[19451]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER Oct 11 21:12:50 media ntpd[1599]: Listen normally on 6 lo 127.0.0.1 UDP 123 Oct 11 21:12:50 media ntpd[1599]: peers refreshed Oct 11 21:12:50 media ntpd[1599]: new interface(s) found: waking up resolver Oct 11 21:12:51 media dhcpcd[19451]: br0: carrier acquired Oct 11 21:12:51 media dhcpcd[19451]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER Oct 11 21:12:51 media kernel: e1000e: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx Oct 11 21:12:51 media kernel: br0: port 1(eth1) entered forwarding state Oct 11 21:12:51 media kernel: br0: port 1(eth1) entered forwarding state Oct 11 21:12:51 media dhcpcd[19451]: br0: using ClientID 01:bc:5f:f4:bc:17:55 Oct 11 21:12:51 media dhcpcd[19451]: br0: soliciting a DHCP lease Oct 11 21:12:51 media dhcpcd[19451]: br0: sending DISCOVER (xid 0x2512f85f), next in 4.47 seconds Oct 11 21:12:51 media dhcpcd[19451]: br0: offered 192.168.20.150 from 192.168.20.1 Oct 11 21:12:51 media dhcpcd[19451]: br0: sending REQUEST (xid 0x2512f85f), next in 3.07 seconds Oct 11 21:12:51 media dhcpcd[19451]: br0: acknowledged 192.168.20.150 from 192.168.20.1 Oct 11 21:12:51 media dhcpcd[19451]: br0: checking for 192.168.20.150 Oct 11 21:12:51 media dhcpcd[19451]: br0: sending ARP probe (1 of 3), next in 1.25 seconds Oct 11 21:12:52 media dhcpcd[19451]: br0: sending ARP probe (2 of 3), next in 1.57 seconds Oct 11 21:12:54 media dhcpcd[19451]: br0: sending ARP probe (3 of 3), next in 2.00 seconds Oct 11 21:12:56 media dhcpcd[19451]: br0: leased 192.168.20.150 for 86400 seconds Oct 11 21:12:56 media dhcpcd[19451]: br0: renew in 43200 seconds, rebind in 75600 seconds Oct 11 21:12:56 media dhcpcd[19451]: br0: adding IP address 192.168.20.150/24 Oct 11 21:12:56 media dhcpcd[19451]: br0: adding host route to 192.168.20.150 via 127.0.0.1 Oct 11 21:12:56 media dhcpcd[19451]: br0: adding route to 192.168.20.0/24 Oct 11 21:12:56 media dhcpcd[19451]: br0: adding default route via 192.168.20.1 Oct 11 21:12:56 media dhcpcd[19451]: br0: writing lease `/var/lib/dhcpcd/dhcpcd-br0.lease' Oct 11 21:12:56 media dhcpcd[19451]: br0: executing `/lib/dhcpcd/dhcpcd-run-hooks' BOUND Oct 11 21:12:56 media dhcpcd[19451]: br0: sending ARP announce (1 of 2), next in 2.00 seconds Oct 11 21:12:58 media ntpd[1599]: Listen normally on 7 br0 192.168.20.150 UDP 123 Oct 11 21:12:58 media ntpd[1599]: peers refreshed Oct 11 21:12:58 media ntpd[1599]: new interface(s) found: waking up resolver Oct 11 21:12:58 media dhcpcd[19451]: br0: sending ARP announce (2 of 2) Oct 11 21:13:06 media kernel: br0: port 1(eth1) entered forwarding state Oct 11 21:14:18 media kernel: mdcmd (63): spindown 8 Oct 11 21:26:38 media kernel: mdcmd (64): spindown 7 Oct 11 21:26:49 media kernel: mdcmd (65): spindown 9 Oct 11 21:50:00 media kernel: mdcmd (66): spindown 2 Oct 11 21:50:01 media kernel: mdcmd (67): spindown 3 Oct 11 21:50:01 media kernel: mdcmd (68): spindown 8 Oct 11 21:50:02 media kernel: mdcmd (69): spindown 10 Oct 11 22:44:24 media emhttp: read_line: read_line: input line too long Oct 11 22:44:30 media emhttp: read_line: read_line: input line too long Oct 11 22:44:36 media emhttp: read_line: read_line: input line too long syslog-deluge.txt
October 12, 201411 yr Author Okay, enabled the -d2 in the go file and rebooted. it doesn't take long for the GUI to become non-responsive/unavailable. I tried deleting cookies in Firefox, and then I was able to get into the GUI again. I have a syslog from after the first 'failure', but before deleting cookies, then another one after resetting cookies, in case there is information there that helps figure out why resetting cookies 'fixes' the issue. I'll wait for input before making any more changes. thanks. syslog-deluge2.zip syslog-deluge3.zip
October 12, 201411 yr I suspect what's happening is that the Deluge webui is sending a very long cookie to the browser. Later when you request a normal page from the unRaid webGui, the browser is sending the same cookie in the header lines included with the GET request. This is because the browser doesn't know which UI it's talking to - the unRaid webGui is on the same IP address as the Deluge webui (port is not taken into account). When emhttp was coded up I looked at apache to see how they handled header lines. In the code I looked at the max length was set at 1024 and so that's what I set for emhttp. It turns out cookies can be up 4093 bytes: http://stackoverflow.com/questions/640938/what-is-the-maximum-size-of-a-web-browsers-cookies-key (4093 is common but according to RFC they can be arbitrarily sized). When emhttp header line buffer size is reached it treats this as an error condition and closes the connection. But now every time you click Refresh the browser issues the same GET request with the same long cookie, with the same result (looks like browser is hung). You should be able to test this theory by firing up a different browser, or connect via different PC and find that webGui is still working. If this is the case, then I will add necessary code to fix this. BTW, the unRaid webGui does not generate or store any cookie data.
Archived
This topic is now archived and is closed to further replies.