Opened 15 years ago
Last modified 13 years ago
#400 new defect
bitten-slave reports internal server error
| Reported by: | t.s@… | Owned by: | osimons |
|---|---|---|---|
| Priority: | critical | Milestone: | 0.6.1 |
| Component: | General | Version: | dev |
| Keywords: | server error 500, bitten-slave | Cc: | |
| Operating System: | Linux |
Description
Recently we upgraded to Ubuntu 9.04 and with that to Trac 0.11.1. Also all plugins were updated including Bitten to revision 641.
But now the bitten-slave aborts after the subversion checkout. It stops with the following messages:
2009-05-27 12:13:35,250 [bitten.build.shtools] INFO: Ausgecheckt, Revision 3207. 2009-05-27 12:13:35,250 [bitten.slave] INFO: Build step checkout completed successfully 2009-05-27 12:13:35,265 [bitten.slave] DEBUG: Sending POST request to 'http://193.1.1.77/trac/xy/builds/2905/steps/' 2009-05-27 12:13:36,312 [bitten.slave] WARNING: Server returned error 500: Internal Server Error 2009-05-27 12:13:36,328 [bitten.slave] DEBUG: Removing build directory C:\Programmierung\Projekte\xy\build_UnitTests_2905 2009-05-27 12:13:53,171 [bitten.slave] ERROR: HTTP Error 500: Internal Server Error
The build recipe step after checkout looks like this (including svn co)
<step id="checkout" description="Checkout source from repository">
<svn:checkout url="http://193.1.1.77/svn/xy" path="${path}" revision="${revision}" />
</step>
<step id="callQmake" description="Call Qmake for project file">
<sh:exec executable="qmake" args="src/UnitTest/UnitTest.pro CONFIG-=debug CONFIG-=release CONFIG+=debug_and_release" />
</step>
This happens for Windows and Linux, where the bitten-slave is running on.
Do you need any further info? I didn't find any server side debug info, which might be helpful.
Attachments (0)
Change History (9)
comment:1 Changed 15 years ago by anonymous
comment:2 Changed 15 years ago by ts@…
After enabling the Trac debug log and have look on it, I found the place causing the problem. In our project directory the sub directory log/bitten was created by the root. Thus www-data had no write access to it. So I changed the owner of this folder to www-data and all works fine.
comment:3 Changed 15 years ago by marc.waeckerlin@…
Acces rights for www-data is not the problem in my installation:
marc@pegasos:~$ ls -lR /net/trac/libxml-cxx/log /net/trac/libxml-cxx/log: insgesamt 0 drwxr-xr-x 2 www-data www-data 0 2009-05-29 13:36 bitten /net/trac/libxml-cxx/log/bitten: insgesamt 40 -rwxr--r-- 1 www-data www-data 857 2009-05-29 13:36 23.log -rwxr--r-- 1 www-data www-data 180 2009-05-29 13:25 23.log.levels -rwxr--r-- 1 www-data www-data 58 2009-05-29 13:26 24.log.levels -rwxr--r-- 1 www-data www-data 490 2009-05-29 13:26 25.log.levels -rwxr--r-- 1 www-data www-data 9140 2009-05-29 13:26 26.log.levels -rwxr--r-- 1 www-data www-data 4515 2009-05-29 13:26 27.log -rwxr--r-- 1 www-data www-data 280 2009-05-29 13:26 27.log.levels
and on another host with the same problem:
marc@dev0002:~$ ls -lR /var/trac/swissstick/log /var/trac/swissstick/log: insgesamt 0 drwxr-xr-x 2 www-data www-data 99 2009-05-05 14:59 bitten /var/trac/swissstick/log/bitten: insgesamt 652 -rw-r--r-- 1 www-data www-data 1973 2009-05-05 14:57 1.log -rw-r--r-- 1 www-data www-data 350 2009-05-05 14:57 1.log.levels -rw-r--r-- 1 www-data www-data 268679 2009-05-05 14:57 2.log -rw-r--r-- 1 www-data www-data 17320 2009-05-05 14:57 2.log.levels -rw-r--r-- 1 www-data www-data 333355 2009-05-05 14:59 3.log -rw-r--r-- 1 www-data www-data 31719 2009-05-05 14:59 3.log.levels
So there must be a different reason for the 500 Internal Server Error on access to builds/<num>/steps/.
comment:4 Changed 15 years ago by marc.waeckerlin@…
No chance. I just removed all build logs, invalidated all builds, made sure the only owner of the whole trac mount is www-data.www-data and then tried again. Result: Aborted in step 5 with the well known problem:
[...] [INFO ] Build step check completed successfully [DEBUG ] Sending POST request to 'https://mrw.dnsalias.org/projects/libxml-cxx/builds/5/steps/' [WARNING ] Server returned error 500: Internal Server Error [DEBUG ] Removing build directory /tmp/bittenRPzG93/build_Default-Build_5 [ERROR ] HTTP Error 500: Internal Server Error [DEBUG ] Removing temporary directory /tmp/bittenRPzG93
It seems to have nothing to do with ownership of files.
FYI: On this system, I mount the trac files over Samba (CIFS) in /etc/fstab (just in case this is part of the problem, but I have a similar behaviour on another system, where the trac files are on the local harddrive, so I suppose this is not the problem):
//servername/trac /net/trac cifs credentials=/etc/samba/credentials-file,iocharset=utf8,soft,nobrl,uid=www-data,gid=www-data 0 0
comment:5 Changed 15 years ago by ts@…
In the admin settings you can enable debug logging for the trac server. This helped me out to find a solution for my problem. Enable it and have a look, what might be going wrong.
comment:6 Changed 15 years ago by marc.waeckerlin@…
First of all, the Samba-Export of my QNap-NAS is a problem, well now it was, I switched from CIFS to NFS. All other FS-Problems now are resolved.
But still the build-problem remains.
Here's the DEBUG-log:
2009-06-04 09:59:58,503 Trac[main] DEBUG: Dispatching <Request "POST u'/builds'">
2009-06-04 09:59:58,852 Trac[queue] DEBUG: Ignoring older revisions for configuration u'Default-Build' on u'Linux'
2009-06-04 09:59:59,199 Trac[queue] DEBUG: Ignoring older revisions for configuration u'Generate-Doku' on u'Linux'
2009-06-04 09:59:59,207 Trac[master] INFO: Build slave 'dev0001' connected from 62.65.151.220
2009-06-04 09:59:59,208 Trac[master] DEBUG: Build slave configuration: {'name': 'dev0001', 'family': 'posix', 'machine': 'x86_64', 'version': '2.6.28-11-generic', 'ipnr': '62.65.151.220', 'os': 'Linux', 'processor': ''}
2009-06-04 09:59:59,354 Trac[queue] DEBUG: Slave 'dev0001' matched target platform u'Linux' of build configuration u'Default-Build'
2009-06-04 09:59:59,429 Trac[queue] DEBUG: Slave 'dev0001' matched target platform u'Linux' of build configuration u'Generate-Doku'
2009-06-04 10:00:00,072 Trac[main] DEBUG: 67 unreachable objects found.
2009-06-04 10:00:00,793 Trac[main] DEBUG: Dispatching <Request "GET u'/builds/3'">
2009-06-04 10:00:00,813 Trac[svn_fs] DEBUG: Subversion bindings imported
2009-06-04 10:00:00,900 Trac[api] DEBUG: action controllers for ticket workflow: ['ConfigurableTicketWorkflow']
2009-06-04 10:00:01,139 Trac[master] INFO: Build slave u'dev0001' initiated build 3
2009-06-04 10:00:01,298 Trac[notify] INFO: BittenNotify invoked for build <Build 3>
2009-06-04 10:00:01,299 Trac[notify] DEBUG: build status: I
2009-06-04 10:00:01,397 Trac[master] INFO: Build slave u'dev0001' initiated build 3
2009-06-04 10:00:01,489 Trac[main] DEBUG: 258 unreachable objects found.
2009-06-04 10:00:09,272 Trac[main] DEBUG: Dispatching <Request "POST u'/builds/3/steps/'">
2009-06-04 10:00:09,675 Trac[master] DEBUG: Slave dev0001 (build 3) completed step 0 (checkout) with status success
2009-06-04 10:00:10,005 Trac[main] DEBUG: 722 unreachable objects found.
2009-06-04 10:00:44,237 Trac[main] DEBUG: Dispatching <Request "POST u'/builds/3/steps/'">
2009-06-04 10:00:47,475 Trac[master] DEBUG: Slave dev0001 (build 3) completed step 1 (make) with status success
2009-06-04 10:00:48,841 Trac[main] DEBUG: 25087 unreachable objects found.
2009-06-04 10:00:53,853 Trac[main] DEBUG: Dispatching <Request "POST u'/builds/3/steps/'">
2009-06-04 10:00:54,296 Trac[master] DEBUG: Slave dev0001 (build 3) completed step 2 (check) with status success
2009-06-04 10:00:54,499 Trac[main] ERROR: Report already exists
Traceback (most recent call last):
File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 423, in _dispatch_request
dispatcher.dispatch(req)
File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 197, in dispatch
resp = chosen_handler.process_request(req)
File "/usr/local/lib/python2.6/dist-packages/Bitten-0.6dev_r641-py2.6.egg/bitten/master.py", line 102, in process_request
return self._process_build_step(req, config, build)
File "/usr/local/lib/python2.6/dist-packages/Bitten-0.6dev_r641-py2.6.egg/bitten/master.py", line 277, in _process_build_step
report.insert(db=db)
File "/usr/local/lib/python2.6/dist-packages/Bitten-0.6dev_r641-py2.6.egg/bitten/model.py", line 904, in insert
db=db)), 'Report already exists'
AssertionError: Report already exists
2009-06-04 10:00:54,503 Trac[perm] DEBUG: No policy allowed anonymous performing TRAC_ADMIN on None
2009-06-04 10:00:54,872 Trac[chrome] DEBUG: Prepare chrome data for request
2009-06-04 10:00:54,891 Trac[perm] DEBUG: No policy allowed anonymous performing BUILD_ADMIN on None
2009-06-04 10:00:54,892 Trac[perm] DEBUG: No policy allowed anonymous performing BUILD_MODIFY on None
2009-06-04 10:00:54,893 Trac[perm] DEBUG: No policy allowed anonymous performing BLOG_ADMIN on <Resource 'blog'>
2009-06-04 10:00:54,894 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_GRANT on None
2009-06-04 10:00:54,895 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_REVOKE on None
2009-06-04 10:00:54,896 Trac[perm] DEBUG: No policy allowed anonymous performing TICKET_ADMIN on None
2009-06-04 10:00:54,903 Trac[perm] DEBUG: No policy allowed anonymous performing EMAIL_VIEW on None
2009-06-04 10:00:55,462 Trac[main] DEBUG: 3143 unreachable objects found.
The report might already exist, due to previous unsuccessful attempts. So I invalidated all builds and removed alls log/bitten/* files and retried.
Result: Same problem again''' Again in Step 5.
- What's the problem?
- What's the cure?
comment:7 Changed 15 years ago by osimons
- Owner changed from cmlenz to osimons
#312 closed as duplicate - same issue with Report already exists at the bottom of it. Reading #312 and looking at the data model and basic assert, it suggests the build step produces more than one report of same type for same build and of the same category (not supported):
assert not list(Report.select(self.env, build=self.build, step=self.step, category=self.category, db=db)), 'Report already exists'
I don't know what your recipe step actually does behind the scenes, but is it possible to split it into two steps and see if that works?
comment:8 Changed 15 years ago by osimons
- Milestone changed from 0.6 to 0.6.1
Are you using Postgres? Have you converted from sqlite? If Postgres, could you check the sequence values, and see that they match the current maximum for the relavant keys/tables?
comment:9 Changed 15 years ago by anonymous
I got the same problem when using both trace and figleaf in the build recepie (I played around to get coverage to work). Thanks Osimons for the hint of multiple outputs.
I have exactly the same problem. When I try to compile, I get:
The place, where this happens is variable. Sometimes it's on the first try to access .../steps/, somtimes the first few steps work and it breaks later (i.e. when I remove all previous builds and remove the trac's log/bitten/... files, then e.g. last time I got up to the step for Cpp Unit-check, then it failed, so milage may vary, but sooner or later the final result is always this error message).
On this address (https://mrw.dnsalias.org/projects/libxml-cxx/builds/3/steps/), my trac homepage returns: Error: Method Not Allowed and the apache log writes the following entries during a build:
My build-recipe is:
<build xmlns:python="http://bitten.cmlenz.net/tools/python" xmlns:c="http://bitten.cmlenz.net/tools/c" xmlns:svn="http://bitten.cmlenz.net/tools/svn"> <step id="checkout" description="Checkout the Files"> <svn:export url="https://mrw.dnsalias.org/svn/libxml-cxx" path="${path}" revision="${revision}" /> </step> <step id="make" description="Compile"> <c:autoreconf force="1" install="1" warnings="cross,syntax,error"/> <c:configure /> <c:make /> </step> <step id="check" description="Unit Tests"> <c:make target="check" /> <c:cppunit file="test/.libs/lt-xml_test.xml" /> <c:cppunit file="test/.libs/lt-serialization_test.xml" /> <c:cppunit file="test/.libs/lt-container_serialization_test.xml" /> </step> </build>I use Ubuntu 9.04 too, on client and server.