BrowserLogin i loop - Githubissues

BjornGrylls commented 4 years ago

Hej Du burde nok flytte browserLogin ud af det loop den er i. Den laver en session for hver uge man vil hente. Lectio er ikke fan af at man logger ind 25 gange på under et sekund.

soeren-b-c commented 4 years ago

@BjornGrylls Tak for tippet - det vil jeg kigge på.

I øvrigt, ren nysgerrighed... hvad har fået dig til at kigge på koden her? Bruger du det selv, eller bare tilfældighedernes spil?

BjornGrylls commented 4 years ago

Lyder godt. Jeg har prøvet, men de Node js promises driller. Jeg har aldrig brugt Node js eller Puppeteer før.

Jeg ville hoste det selv på Heroku, men det har vist sig mere vanskeligt end som så. Btw tak for at dele koden ;)

soeren-b-c commented 4 years ago

@BjornGrylls Velbekomme.

Jeg lover intet, men hvis du deler dine fejlmeddelelser vil jeg gerne forsøge at kigge på det. (Jeg har dog aldrig brug Heroku.) Opret evt. et nyt Issue.

BjornGrylls commented 4 years ago

Logs ved 25 loginforsøg / sekundet:

2020-09-08T09:15:30.321728+00:00 heroku[router]: sock=backend at=error code=H18 desc="Server Request Interrupted" method=GET path="/?skole=575&elev=43439479846&uger=25" host=lectio2ics-service.herokuapp.com request_id=061e7712-6543-4d79-a607-9baf6399965c fwd="185.22.75.1" dyno=web.1 connect=1ms service=653ms status=503 bytes= protocol=https 2020-09-08T09:15:30.312459+00:00 app[web.1]: events.js:292 2020-09-08T09:15:30.312467+00:00 app[web.1]: throw er; // Unhandled 'error' event 2020-09-08T09:15:30.312468+00:00 app[web.1]: ^ 2020-09-08T09:15:30.312468+00:00 app[web.1]: 2020-09-08T09:15:30.312469+00:00 app[web.1]: Error: read ENOTCONN 2020-09-08T09:15:30.312469+00:00 app[web.1]: at tryReadStart (net.js:573:20) 2020-09-08T09:15:30.312470+00:00 app[web.1]: at Socket._read (net.js:584:5) 2020-09-08T09:15:30.312470+00:00 app[web.1]: at Socket.Readable.read (_stream_readable.js:467:10) 2020-09-08T09:15:30.312471+00:00 app[web.1]: at Socket.read (net.js:624:39) 2020-09-08T09:15:30.312471+00:00 app[web.1]: at new Socket (net.js:376:12) 2020-09-08T09:15:30.312472+00:00 app[web.1]: at Object.Socket (net.js:267:41) 2020-09-08T09:15:30.312472+00:00 app[web.1]: at createSocket (internal/child_process.js:314:14) 2020-09-08T09:15:30.312472+00:00 app[web.1]: at ChildProcess.spawn (internal/child_process.js:437:23) 2020-09-08T09:15:30.312473+00:00 app[web.1]: at Object.spawn (child_process.js:548:9) 2020-09-08T09:15:30.312473+00:00 app[web.1]: at Launcher.launch (/app/node_modules/puppeteer/lib/Launcher.js:126:40) 2020-09-08T09:15:30.312474+00:00 app[web.1]: Emitted 'error' event on Socket instance at: 2020-09-08T09:15:30.312474+00:00 app[web.1]: at emitErrorNT (internal/streams/destroy.js:92:8) 2020-09-08T09:15:30.312474+00:00 app[web.1]: at emitErrorAndCloseNT (internal/streams/destroy.js:60:3) 2020-09-08T09:15:30.312475+00:00 app[web.1]: at processTicksAndRejections (internal/process/task_queues.js:84:21) { 2020-09-08T09:15:30.312475+00:00 app[web.1]: errno: 'ENOTCONN', 2020-09-08T09:15:30.312476+00:00 app[web.1]: code: 'ENOTCONN', 2020-09-08T09:15:30.312476+00:00 app[web.1]: syscall: 'read' 2020-09-08T09:15:30.312476+00:00 app[web.1]: } 2020-09-08T09:15:30.326491+00:00 app[web.1]: npm ERR! code ELIFECYCLE 2020-09-08T09:15:30.326742+00:00 app[web.1]: npm ERR! errno 1 2020-09-08T09:15:30.329398+00:00 app[web.1]: npm ERR! node-lectio@1.2.0 start: NODE_ENV=production node -r reify node-lectio.js 2020-09-08T09:15:30.329500+00:00 app[web.1]: npm ERR! Exit status 1 2020-09-08T09:15:30.329653+00:00 app[web.1]: npm ERR! 2020-09-08T09:15:30.329758+00:00 app[web.1]: npm ERR! Failed at the node-lectio@1.2.0 start script. 2020-09-08T09:15:30.329846+00:00 app[web.1]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above. 2020-09-08T09:15:30.348259+00:00 app[web.1]: 2020-09-08T09:15:30.348900+00:00 app[web.1]: npm ERR! A complete log of this run can be found in: 2020-09-08T09:15:30.349109+00:00 app[web.1]: npm ERR! /app/.npm/_logs/2020-09-08T09_15_30_331Z-debug.log

Ligger på https://lectio2ics-service.herokuapp.com/?skole=575&elev=43439479846&uger=25 men du burde få samme resultat hvis du kører den lokalt.

soeren-b-c commented 4 years ago

@BjornGrylls

Opklarende spørgsmål:

Du skriver "ved 25 loginforsøg / sekund". Skal det forstå sådan at du sagtens kan få det til at fungere ved bare at hente en enkelt persons skema for en enkelt uge, men når du skalerer op, så går det i stykker?
Må jeg se indholdet af /app/.npm/_logs/2020-09-08T09_15_30_331Z-debug.log

BjornGrylls commented 4 years ago

@soeren-b-c

Korrekt. Hvis jeg ikke bruger "uger" variablen i URL'en så henter den nuværende og næste uges skema. Men allerede ved 5 uger så dør den.

node-lectio.js:

    if (String(typeof qs.uger) == 'undefined') {
      var amount = 2;
    }
    else {
      var amount = Number(qs.uger);
    }

qs = query string.

Jeg kan tilgå en bash konsol til appen, men mappen "app" findes ikke:

soeren-b-c commented 4 years ago

Jeg henter uden problemer 10 uger når jeg bruger scriptet, så der er nok en flaskehals et sted i dit setup. (Alternativt har du som elev væsentligt mere i dit skema på en uge, end jeg har som lærer, og det er der skoen trykker.)

Bemærk / i starten af adressen til den logfil jeg spørger til.

Prøv evt.

cd /app/.npm/_logs/
less 2020-09-08T09_15_30_331Z-debug.log

BjornGrylls commented 4 years ago

Den kan være fordi den er for langsom. Når puppeteer lukker browseren så kan de resterende promises ikke forbinde? Logs ved 4 uger:

2020-09-09T18:12:29.578623+00:00 heroku[web.1]: Starting process with command npm start 2020-09-09T18:12:31.530209+00:00 app[web.1]: 2020-09-09T18:12:31.530229+00:00 app[web.1]: > node-lectio@1.2.0 start /app 2020-09-09T18:12:31.530230+00:00 app[web.1]: > NODE_ENV=production node -r reify node-lectio.js 2020-09-09T18:12:31.530230+00:00 app[web.1]: 2020-09-09T18:12:31.816047+00:00 app[web.1]: Listening on 56236 2020-09-09T18:12:32.286932+00:00 heroku[web.1]: State changed from starting to up 2020-09-09T18:12:34.457024+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx 2020-09-09T18:12:34.516226+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx 2020-09-09T18:12:34.519662+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx 2020-09-09T18:12:34.522768+00:00 app[web.1]: Logging in to https://www.lectio.dk/lectio/575/login.aspx 2020-09-09T18:12:35.684839+00:00 app[web.1]: $Typing username in #username 2020-09-09T18:12:35.728186+00:00 app[web.1]: Typing password 2020-09-09T18:12:35.778854+00:00 app[web.1]: Clicking button 2020-09-09T18:12:36.174349+00:00 app[web.1]: $Typing username in #username 2020-09-09T18:12:36.175412+00:00 app[web.1]: $Typing username in #username 2020-09-09T18:12:36.207686+00:00 app[web.1]: $Typing username in #username 2020-09-09T18:12:36.226083+00:00 app[web.1]: Typing password 2020-09-09T18:12:36.231054+00:00 app[web.1]: Typing password 2020-09-09T18:12:36.264303+00:00 app[web.1]: Typing password 2020-09-09T18:12:36.279348+00:00 app[web.1]: Clicking button 2020-09-09T18:12:36.281851+00:00 app[web.1]: Clicking button 2020-09-09T18:12:36.318025+00:00 app[web.1]: Clicking button 2020-09-09T18:12:38.207645+00:00 app[web.1]: Button clicked 2020-09-09T18:12:38.275909+00:00 app[web.1]: Button clicked 2020-09-09T18:12:38.387347+00:00 app[web.1]: Fetching https://www.lectio.dk/lectio/575/SkemaNy.aspx?type=elev&elevid=43439479846&week=382020 2020-09-09T18:12:38.390585+00:00 app[web.1]: Fetching https://www.lectio.dk/lectio/575/SkemaNy.aspx?type=elev&elevid=43439479846&week=402020 2020-09-09T18:12:39.255483+00:00 app[web.1]: Button clicked 2020-09-09T18:12:39.292822+00:00 app[web.1]: Button clicked 2020-09-09T18:12:39.486994+00:00 app[web.1]: Stopping browser… 2020-09-09T18:12:39.516641+00:00 app[web.1]: Task complete. 2020-09-09T18:12:39.681855+00:00 app[web.1]: Stopping browser… 2020-09-09T18:12:39.715234+00:00 app[web.1]: Task complete. 2020-09-09T18:13:34.741342+00:00 heroku[router]: at=error code=H15 desc="Idle connection" method=GET path="/?skole=575&elev=43439479846&uger=4" host=lectio2ics-service.herokuapp.com request_id=11906fac-6459-4b2c-b358-4b2cf9acb298 fwd="212.98.73.119" dyno=web.1 connect=0ms service=60667ms status=503 bytes= protocol=https

Den sender uge 38 og 40, men resten dukker aldrig op (da puppteer er lukket) og den timer ud.

Desværre heller ikke.

soeren-b-c / lectio-skema-til-.ics-kalender

BrowserLogin i loop #14